node2
V: t+0.01s : [VirtualNode 169.254.68.230] received MMCP message (MmcpPing) from 169.254.41.107
V: t+0.02s : [VirtualNode 169.254.68.230] Received ping(id=1533913366) from 169.254.41.107
V: t+0.02s : [VirtualNode 169.254.68.230] Sending pong to 169.254.41.107
V: t+0.02s : [VirtualNode 169.254.41.107] received MMCP message (MmcpPong) from 169.254.68.230
D: t+0.02s : [VirtualNode 169.254.68.230] Incoming packet received, but no socket listening on: 0
V: t+0.02s : [VirtualNode 169.254.68.230] received MMCP message (MmcpOriginatorMessage) from 169.254.41.107
V: t+0.02s : [OriginatingMessageManager for /169.254.68.230] received originating message from 169.254.41.107 via 169.254.41.107
V: t+0.02s : [VirtualNode 169.254.41.107] Received pong(id=2)}
V: t+0.02s : [OriginatingMessageManager for /169.254.68.230] received originating message from 169.254.41.107 via 169.254.41.107 messageId=2 hopCount=1 sentTime=1699269613717 Currently known: senttime=1699269613715 hop count = 1 isMoreRecentOrBetter=true
V: t+0.02s : [OriginatingMessageManager for /169.254.68.230] update originator messages: currently known nodes = 169.254.41.107
W: t+0.02s : [OriginatingMessageManager for /169.254.41.107] : onPongReceived : pong from 169.254.68.230 does not match any known sent ping
D: t+0.02s : [VirtualNode 169.254.41.107] Incoming packet received, but no socket listening on: 0
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.41.107 ] : run : finished
I: t+0.02s : [ChainSocketServer: 169.254.41.107] closed
I: t+0.02s : [ChainSocketServer: 169.254.68.230] closed
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.68.230 ] : run : finished
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 13513 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 49145 waiting for first packet
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:49145
D: t+0.0s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269613732 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269613732
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269613732 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269613733
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269613733 Currently known: senttime=1699269613732 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
I: t+0.03s : [ChainSocketFactoryImpl for /169.254.1.1] created socket to /169.254.1.2:44987 nexthop = /127.0.0.1:44987
I: t+0.03s : [ChainSocketServer: 169.254.1.1] closed
D: t+0.03s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
I: t+0.03s : [ChainSocketServer: 169.254.1.2] closed
D: t+0.03s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 8200 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 60395 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.3 ] Started on 10235 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.3] init
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:60395
D: t+0.01s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269613772 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269613772
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269613772 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269613773
V: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269613773 Currently known: senttime=1699269613772 hop count = 1 isMoreRecentOrBetter=true
D: t+0.01s : [VirtualNode 169.254.1.2] addNewNeighborConnection connection to virtual addr 169.254.1.3 via datagram to localhost/127.0.0.1:10235
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
D: t+0.01s : [OriginatingMessageManager for /169.254.1.2] : addNeighbor - sending originating messages out
V: t+0.01s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=2 hopCount=1 sentTime=1699269613774 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=1 sentTime=1699269613775
V: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=1 hopCount=1 sentTime=1699269613775 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269613776
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269613776 Currently known: senttime=1699269613772 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269613776 Currently known: senttime=1699269613774 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 messageId=1 hopCount=2 sentTime=1699269613775 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=3 sentTime=1699269614763
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=3 hopCount=1 sentTime=1699269614763 Currently known: senttime=1699269613773 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] pingNeighborsRunnable: send ping to 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.1 lasthop=169.254.1.1 send to 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=4 sentTime=1699269614765
V: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=4) from 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.1 via 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] Sending pong to 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.1
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.1 via 169.254.1.2 messageId=3 hopCount=2 sentTime=1699269614763 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=4 hopCount=1 sentTime=1699269614765 Currently known: senttime=1699269613776 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=4 hopCount=1 sentTime=1699269614765 Currently known: senttime=1699269613776 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=2 sentTime=1699269614766
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPong) from 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.1] Received pong(id=6)}
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=2 hopCount=1 sentTime=1699269614766 Currently known: senttime=1699269613775 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpPing) from 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] pingNeighborsRunnable: send ping to 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received ping from 169.254.1.2 pingTime=3
V: t+1.0s : [VirtualNode 169.254.1.3] Received ping(id=5) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.3] Sending pong to 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=3) from 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.2] Sending pong to 169.254.1.3
D: t+1.0s : [VirtualNode 169.254.1.3] Incoming packet received, but no socket listening on: 0
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpPong) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPong) from 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.3] Received pong(id=8)}
V: t+1.0s : [VirtualNode 169.254.1.2] Received pong(id=4)}
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received ping from 169.254.1.2 pingTime=1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received ping from 169.254.1.3 pingTime=3
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
D: t+1.0s : [VirtualNode 169.254.1.3] Incoming packet received, but no socket listening on: 0
D: t+1.0s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPing) from 169.254.1.2
I: t+1.0s : [ChainSocketServer: 169.254.1.1] closed
V: t+1.0s : [VirtualNode 169.254.1.1] Received ping(id=7) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.1] Sending pong to 169.254.1.2
I: t+1.0s : [ChainSocketServer: 169.254.1.2] closed
D: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
I: t+1.0s : [ChainSocketServer: 169.254.1.3] closed
D: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.3 ] : run : finished
E: t+1.0s : [VirtualNode 169.254.1.1] : route : exception routing packet from 169.254.1.1 java.net.SocketException: Socket closed
at java.base/sun.nio.ch.DatagramSocketAdaptor.send(DatagramSocketAdaptor.java:222)
at java.base/java.net.DatagramSocket.send(DatagramSocket.java:664)
at com.ustadmobile.meshrabiya.vnet.VirtualNodeDatagramSocket.send(VirtualNodeDatagramSocket.kt:89)
at com.ustadmobile.meshrabiya.vnet.VirtualNode.route(VirtualNode.kt:488)
at com.ustadmobile.meshrabiya.vnet.VirtualRouter$DefaultImpls.route$default(VirtualRouter.kt:22)
at com.ustadmobile.meshrabiya.vnet.VirtualNode.onIncomingMmcpMessage(VirtualNode.kt:370)
at com.ustadmobile.meshrabiya.vnet.VirtualNode.route(VirtualNode.kt:445)
at com.ustadmobile.meshrabiya.vnet.VirtualNodeDatagramSocket.run(VirtualNodeDatagramSocket.kt:64)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.nio.channels.ClosedChannelException
at java.base/sun.nio.ch.DatagramChannelImpl.ensureOpen(DatagramChannelImpl.java:267)
at java.base/sun.nio.ch.DatagramChannelImpl.blockingSend(DatagramChannelImpl.java:850)
at java.base/sun.nio.ch.DatagramSocketAdaptor.send(DatagramSocketAdaptor.java:218)
... 12 more
D: t+1.01s : Drop mmcp packet from -1442971390
D: t+1.01s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
D: t+1.01s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 58849 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 30980 waiting for first packet
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.3 ] Started on 60074 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.3] init
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:30980
D: t+0.0s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269614785 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269614786
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269614786 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269614786
D: t+0.01s : [VirtualNode 169.254.1.2] addNewNeighborConnection connection to virtual addr 169.254.1.3 via datagram to localhost/127.0.0.1:60074
V: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
D: t+0.01s : [OriginatingMessageManager for /169.254.1.2] : addNeighbor - sending originating messages out
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269614786 Currently known: senttime=1699269614785 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.01s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=2 hopCount=1 sentTime=1699269614787 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=1 sentTime=1699269614790
V: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=1 hopCount=1 sentTime=1699269614790 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+0.01s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 messageId=1 hopCount=2 sentTime=1699269614790 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269614792
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
V: t+0.01s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269614792 Currently known: senttime=1699269614787 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269614792 Currently known: senttime=1699269614786 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
D: t+0.02s : [ChainSocketServer: 169.254.1.2] accepted new client
/127.0.0.1:30980 is not final destination - write init request and get response
D: t+0.02s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : init client - reading init request...
D: t+0.02s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : receive init request to connect to /169.254.1.3:36845
I: t+0.02s : [ChainSocketFactoryImpl for /169.254.1.2] created socket to /169.254.1.3:36845 nexthop = /127.0.0.1:36845
D: t+0.02s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : created onward socket
D: t+0.02s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : wrote chain init response
/127.0.0.1:30980 got init response
I: t+0.02s : [ChainSocketFactoryImpl for /169.254.1.1] created socket to /169.254.1.3:36845 nexthop = /127.0.0.1:30980
V: t+0.02s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : CopyStream: onwardToIncoming - start copying input to output
V: t+0.03s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : CopyStream: incomingToOnward - start copying input to output
V: t+0.03s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310 : CopyStream: onwardToIncoming - finished copying - reached end of stream
W: t+0.03s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:40310: CopyStream: aborting java.net.SocketException: Socket closed
at java.base/sun.nio.ch.NioSocketImpl.endRead(NioSocketImpl.java:248)
at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:327)
at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
at java.base/java.io.InputStream.read(InputStream.java:218)
at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106)
at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103)
at com.ustadmobile.meshrabiya.vnet.socket.ChainSocketServer$CopyStreamRunnable.run(ChainSocketServer.kt:144)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
I: t+0.03s : [ChainSocketServer: 169.254.1.1] closed
D: t+0.03s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
I: t+0.03s : [ChainSocketServer: 169.254.1.2] closed
D: t+0.03s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
I: t+0.03s : [ChainSocketServer: 169.254.1.3] closed
D: t+0.03s : [VirtualNodeDatagramSocket for 169.254.1.3 ] : run : finished
I: t+0.0s : [ChainSocketServer: 169.254.71.112] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.71.112 ] Started on 60286 waiting for first packet
D: t+0.01s : [VirtualNodeDatagramSocket for 169.254.22.140 ] Started on 46951 waiting for first packet
I: t+0.01s : [ChainSocketServer: 169.254.22.140] init
D: t+0.01s : [VirtualNode 169.254.71.112] addNewNeighborConnection connection to virtual addr 169.254.22.140 via datagram to localhost/127.0.0.1:46951
D: t+0.01s : [OriginatingMessageManager for /169.254.71.112] : addNeighbor - sending originating messages out
V: t+0.01s : [VirtualNode 169.254.22.140] received MMCP message (MmcpOriginatorMessage) from 169.254.71.112
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] received originating message from 169.254.71.112 via 169.254.71.112
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] received originating message from 169.254.71.112 via 169.254.71.112 messageId=1 hopCount=1 sentTime=1699269614825 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] update originator messages: currently known nodes = 169.254.71.112
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] sending originating message messageId=1 sentTime=1699269614826
V: t+0.01s : [VirtualNode 169.254.71.112] received MMCP message (MmcpOriginatorMessage) from 169.254.22.140
V: t+0.01s : [OriginatingMessageManager for /169.254.71.112] received originating message from 169.254.22.140 via 169.254.22.140
V: t+0.01s : [OriginatingMessageManager for /169.254.71.112] received originating message from 169.254.22.140 via 169.254.22.140 messageId=1 hopCount=1 sentTime=1699269614826 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.71.112] update originator messages: currently known nodes = 169.254.22.140
V: t+0.01s : [OriginatingMessageManager for /169.254.71.112] sending originating message messageId=2 sentTime=1699269614827
V: t+0.01s : [VirtualNode 169.254.71.112] received MMCP message (MmcpHotspotRequest) from 169.254.22.140
I: t+0.01s : [VirtualNode 169.254.71.112] Received hotspotrequest (id=-387288174)
D: t+0.01s : [VirtualNode 169.254.71.112] Incoming packet received, but no socket listening on: 0
V: t+0.01s : [VirtualNode 169.254.22.140] received MMCP message (MmcpOriginatorMessage) from 169.254.71.112
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] received originating message from 169.254.71.112 via 169.254.71.112
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] received originating message from 169.254.71.112 via 169.254.71.112 messageId=2 hopCount=1 sentTime=1699269614827 Currently known: senttime=1699269614825 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.22.140] update originator messages: currently known nodes = 169.254.71.112
I: t+0.01s : [VirtualNode 169.254.71.112] sending hotspotresponse to 169.254.22.140
V: t+0.01s : [VirtualNode 169.254.22.140] received MMCP message (MmcpHotspotResponse) from 169.254.71.112
D: t+0.01s : [VirtualNode 169.254.22.140] Incoming packet received, but no socket listening on: 0
I: t+0.01s : [ChainSocketServer: 169.254.71.112] closed
D: t+0.01s : [VirtualNodeDatagramSocket for 169.254.71.112 ] : run : finished
I: t+0.02s : [ChainSocketServer: 169.254.22.140] closed
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.22.140 ] : run : finished
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 12578 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 26640 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:26640
D: t+0.0s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269614848 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269614849
V: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269614849 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269614850
V: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269614850 Currently known: senttime=1699269614848 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
D: t+0.01s : [UdpForwardRule : 33371 -> 169.254.1.2:8000] listening
V: t+0.01s : [VirtualDatagramSocketImpl] bind laddr=/169.254.1.2 lport=8000
D: t+0.01s : [UdpForwardRule : 8000 -> 127.0.0.1:43171] listening
Send packet to localhost/127.0.0.1:33371
V: t+0.01s : [VirtualDatagramSocketImpl] bind laddr=/169.254.1.1 lport=0
V: t+0.01s : [VirtualDatagramSocketImpl] send packet size=5 bytes to /169.254.1.2:8000
V: t+0.01s : [VirtualDatagramSocketImpl] incoming virtual packet=25 bytes from 169.254.1.1:15746
V: t+0.01s : [VirtualDatagramSocketImpl] send packet size=5 bytes to /169.254.1.1:15746
V: t+0.01s : [VirtualDatagramSocketImpl] incoming virtual packet=25 bytes from 169.254.1.2:8000
I: t+0.01s : [ChainSocketServer: 169.254.1.1] closed
D: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
I: t+0.01s : [ChainSocketServer: 169.254.1.2] closed
D: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
I: t+0.0s : [ChainSocketServer: 169.254.13.145] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.13.145 ] Started on 38025 waiting for first packet
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.42.128 ] Started on 1863 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.42.128] init
D: t+0.0s : [VirtualNode 169.254.42.128] addNewNeighborConnection connection to virtual addr 169.254.13.145 via datagram to localhost/127.0.0.1:38025
D: t+0.0s : [OriginatingMessageManager for /169.254.42.128] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.13.145] received MMCP message (MmcpOriginatorMessage) from 169.254.42.128
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.42.128 via 169.254.42.128
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.42.128 via 169.254.42.128 messageId=1 hopCount=1 sentTime=1699269614863 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] update originator messages: currently known nodes = 169.254.42.128
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] sending originating message messageId=1 sentTime=1699269614864
V: t+0.0s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.13.145
V: t+0.0s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.13.145 via 169.254.13.145
V: t+0.0s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.13.145 via 169.254.13.145 messageId=1 hopCount=1 sentTime=1699269614864 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.13.145
V: t+0.0s : [OriginatingMessageManager for /169.254.42.128] sending originating message messageId=2 sentTime=1699269614865
V: t+0.0s : [VirtualNode 169.254.13.145] received MMCP message (MmcpOriginatorMessage) from 169.254.42.128
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.42.128 via 169.254.42.128
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.42.128 via 169.254.42.128 messageId=2 hopCount=1 sentTime=1699269614865 Currently known: senttime=1699269614863 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] update originator messages: currently known nodes = 169.254.42.128
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.7.88 ] Started on 19338 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.7.88] init
D: t+0.0s : [VirtualNode 169.254.7.88] addNewNeighborConnection connection to virtual addr 169.254.13.145 via datagram to localhost/127.0.0.1:38025
D: t+0.0s : [OriginatingMessageManager for /169.254.7.88] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.13.145] received MMCP message (MmcpOriginatorMessage) from 169.254.7.88
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.7.88 via 169.254.7.88
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.7.88 via 169.254.7.88 messageId=1 hopCount=1 sentTime=1699269614867 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.13.145] update originator messages: currently known nodes = 169.254.7.88, 169.254.42.128
V: t+0.01s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.7.88 lasthop=169.254.7.88 send to 169.254.42.128
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] sending originating message messageId=2 sentTime=1699269614868
V: t+0.01s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.7.88
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.7.88 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.7.88 via 169.254.13.145 messageId=1 hopCount=2 sentTime=1699269614867 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.7.88, 169.254.13.145
V: t+0.01s : [VirtualNode 169.254.7.88] received MMCP message (MmcpOriginatorMessage) from 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.13.145 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.13.145 via 169.254.13.145 messageId=2 hopCount=1 sentTime=1699269614868 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] update originator messages: currently known nodes = 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.13.145 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.13.145 via 169.254.13.145 messageId=2 hopCount=1 sentTime=1699269614868 Currently known: senttime=1699269614864 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.7.88, 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] sending originating message messageId=2 sentTime=1699269614868
V: t+0.01s : [VirtualNode 169.254.13.145] received MMCP message (MmcpOriginatorMessage) from 169.254.7.88
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.7.88 via 169.254.7.88
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.7.88 via 169.254.7.88 messageId=2 hopCount=1 sentTime=1699269614868 Currently known: senttime=1699269614867 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] update originator messages: currently known nodes = 169.254.7.88, 169.254.42.128
V: t+0.01s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.7.88 lasthop=169.254.7.88 send to 169.254.42.128
V: t+0.01s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.7.88
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.7.88 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.7.88 via 169.254.13.145 messageId=2 hopCount=2 sentTime=1699269614868 Currently known: senttime=1699269614867 hop count = 2 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.7.88, 169.254.13.145
D: t+0.01s : [VirtualNodeDatagramSocket for 169.254.86.120 ] Started on 41506 waiting for first packet
I: t+0.01s : [ChainSocketServer: 169.254.86.120] init
D: t+0.01s : [VirtualNode 169.254.86.120] addNewNeighborConnection connection to virtual addr 169.254.13.145 via datagram to localhost/127.0.0.1:38025
D: t+0.01s : [OriginatingMessageManager for /169.254.86.120] : addNeighbor - sending originating messages out
V: t+0.01s : [VirtualNode 169.254.13.145] received MMCP message (MmcpOriginatorMessage) from 169.254.86.120
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.86.120 via 169.254.86.120
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.86.120 via 169.254.86.120 messageId=1 hopCount=1 sentTime=1699269614876 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] update originator messages: currently known nodes = 169.254.7.88, 169.254.86.120, 169.254.42.128
V: t+0.01s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.86.120 lasthop=169.254.86.120 send to 169.254.7.88
V: t+0.01s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.86.120 lasthop=169.254.86.120 send to 169.254.42.128
V: t+0.01s : [OriginatingMessageManager for /169.254.13.145] sending originating message messageId=3 sentTime=1699269614876
V: t+0.01s : [VirtualNode 169.254.7.88] received MMCP message (MmcpOriginatorMessage) from 169.254.86.120
V: t+0.01s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.86.120
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.86.120 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.86.120 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.86.120 via 169.254.13.145 messageId=1 hopCount=2 sentTime=1699269614876 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.86.120 via 169.254.13.145 messageId=1 hopCount=2 sentTime=1699269614876 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] update originator messages: currently known nodes = 169.254.86.120, 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.7.88, 169.254.86.120, 169.254.13.145
V: t+0.01s : [VirtualNode 169.254.86.120] received MMCP message (MmcpOriginatorMessage) from 169.254.13.145
V: t+0.01s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.86.120] received originating message from 169.254.13.145 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.13.145 via 169.254.13.145
V: t+0.01s : [VirtualNode 169.254.7.88] received MMCP message (MmcpOriginatorMessage) from 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.86.120] received originating message from 169.254.13.145 via 169.254.13.145 messageId=3 hopCount=1 sentTime=1699269614876 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.13.145 via 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.13.145 via 169.254.13.145 messageId=3 hopCount=1 sentTime=1699269614876 Currently known: senttime=1699269614868 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.86.120] update originator messages: currently known nodes = 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.13.145 via 169.254.13.145 messageId=3 hopCount=1 sentTime=1699269614876 Currently known: senttime=1699269614868 hop count = 1 isMoreRecentOrBetter=true
V: t+0.01s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.7.88, 169.254.86.120, 169.254.13.145
V: t+0.01s : [OriginatingMessageManager for /169.254.7.88] update originator messages: currently known nodes = 169.254.86.120, 169.254.13.145
V: t+0.02s : [OriginatingMessageManager for /169.254.86.120] sending originating message messageId=2 sentTime=1699269614878
V: t+0.02s : [VirtualNode 169.254.13.145] received MMCP message (MmcpOriginatorMessage) from 169.254.86.120
V: t+0.02s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.86.120 via 169.254.86.120
V: t+0.02s : [OriginatingMessageManager for /169.254.13.145] received originating message from 169.254.86.120 via 169.254.86.120 messageId=2 hopCount=1 sentTime=1699269614878 Currently known: senttime=1699269614876 hop count = 1 isMoreRecentOrBetter=true
V: t+0.02s : [OriginatingMessageManager for /169.254.13.145] update originator messages: currently known nodes = 169.254.7.88, 169.254.86.120, 169.254.42.128
V: t+0.02s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.86.120 lasthop=169.254.86.120 send to 169.254.7.88
V: t+0.02s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.86.120 lasthop=169.254.86.120 send to 169.254.42.128
V: t+0.02s : [VirtualNode 169.254.42.128] received MMCP message (MmcpOriginatorMessage) from 169.254.86.120
V: t+0.02s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.86.120 via 169.254.13.145
V: t+0.02s : [OriginatingMessageManager for /169.254.42.128] received originating message from 169.254.86.120 via 169.254.13.145 messageId=2 hopCount=2 sentTime=1699269614878 Currently known: senttime=1699269614876 hop count = 2 isMoreRecentOrBetter=true
V: t+0.02s : [OriginatingMessageManager for /169.254.42.128] update originator messages: currently known nodes = 169.254.7.88, 169.254.86.120, 169.254.13.145
V: t+0.02s : [VirtualNode 169.254.7.88] received MMCP message (MmcpOriginatorMessage) from 169.254.86.120
V: t+0.02s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.86.120 via 169.254.13.145
V: t+0.02s : [VirtualNode 169.254.42.128] broadcast packet from=169.254.42.128 lasthop=0.0.0.0 send to 169.254.13.145
V: t+0.02s : [OriginatingMessageManager for /169.254.7.88] received originating message from 169.254.86.120 via 169.254.13.145 messageId=2 hopCount=2 sentTime=1699269614878 Currently known: senttime=1699269614876 hop count = 2 isMoreRecentOrBetter=true
V: t+0.02s : [OriginatingMessageManager for /169.254.7.88] update originator messages: currently known nodes = 169.254.86.120, 169.254.13.145
V: t+0.02s : [VirtualNode 169.254.13.145] received MMCP message (MmcpPing) from 169.254.42.128
V: t+0.02s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.42.128 lasthop=169.254.42.128 send to 169.254.7.88
V: t+0.02s : [VirtualNode 169.254.13.145] broadcast packet from=169.254.42.128 lasthop=169.254.42.128 send to 169.254.86.120
V: t+0.02s : [VirtualNode 169.254.7.88] received MMCP message (MmcpPing) from 169.254.42.128
V: t+0.02s : [VirtualNode 169.254.86.120] received MMCP message (MmcpPing) from 169.254.42.128
I: t+0.02s : [ChainSocketServer: 169.254.13.145] closed
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.13.145 ] : run : finished
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.42.128 ] : run : finished
I: t+0.02s : [ChainSocketServer: 169.254.42.128] closed
I: t+0.02s : [ChainSocketServer: 169.254.7.88] closed
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.7.88 ] : run : finished
I: t+0.02s : [ChainSocketServer: 169.254.86.120] closed
D: t+0.02s : [VirtualNodeDatagramSocket for 169.254.86.120 ] : run : finished
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 1570 waiting for first packet
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 3993 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
Test node1=169.254.1.1 node2=169.254.1.2
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:3993
D: t+0.0s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269614890 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269614891
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269614891 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269614892
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269614892 Currently known: senttime=1699269614890 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] pingNeighborsRunnable: send ping to 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=3 sentTime=1699269615885
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=4) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] Sending pong to 169.254.1.1
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPong) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.1] Received pong(id=2)}
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received ping from 169.254.1.2 pingTime=1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=3 hopCount=1 sentTime=1699269615885 Currently known: senttime=1699269614892 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
D: t+1.0s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269615888
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPing) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.1] Received ping(id=4) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.1] Sending pong to 169.254.1.2
D: t+1.0s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPong) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] Received pong(id=5)}
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received ping from 169.254.1.1 pingTime=1
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269615888 Currently known: senttime=1699269614891 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+4.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=6 sentTime=1699269618885
V: t+4.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+4.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+4.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=6 hopCount=1 sentTime=1699269618885 Currently known: senttime=1699269615885 hop count = 1 isMoreRecentOrBetter=true
V: t+4.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
I: t+4.0s : [ChainSocketServer: 169.254.1.1] closed
D: t+4.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
I: t+4.0s : [ChainSocketServer: 169.254.1.2] closed
D: t+4.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 3929 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 21304 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.3 ] Started on 24156 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.3] init
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:21304
D: t+0.0s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269618893 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269618893
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269618893 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269618894
D: t+0.0s : [VirtualNode 169.254.1.2] addNewNeighborConnection connection to virtual addr 169.254.1.3 via datagram to localhost/127.0.0.1:24156
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
D: t+0.0s : [OriginatingMessageManager for /169.254.1.2] : addNeighbor - sending originating messages out
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269618894 Currently known: senttime=1699269618893 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=2 hopCount=1 sentTime=1699269618895 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=1 sentTime=1699269618895
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=1 hopCount=1 sentTime=1699269618895 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+0.0s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269618895
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 messageId=1 hopCount=2 sentTime=1699269618895 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
V: t+0.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269618895 Currently known: senttime=1699269618895 hop count = 1 isMoreRecentOrBetter=false
D: t+0.0s : Drop mmcp packet from -1442971390
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269618895 Currently known: senttime=1699269618893 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
test: wait for discovery
test: node 1 knows about node 3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] pingNeighborsRunnable: send ping to 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=3 sentTime=1699269619889
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=4) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] Sending pong to 169.254.1.1
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPong) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.1] Received pong(id=4)}
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received ping from 169.254.1.2 pingTime=1
D: t+1.0s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=3 hopCount=1 sentTime=1699269619889 Currently known: senttime=1699269618894 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.1 lasthop=169.254.1.1 send to 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.1 via 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.1 via 169.254.1.2 messageId=3 hopCount=2 sentTime=1699269619889 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=5 sentTime=1699269619890
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
test: node 3 knows about node 1 : discovery done
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=5 hopCount=1 sentTime=1699269619890 Currently known: senttime=1699269618895 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=5 hopCount=1 sentTime=1699269619890 Currently known: senttime=1699269618895 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.1
V: t+1.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpPing) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.3] Received ping(id=6) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.3] Sending pong to 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPing) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.1] Received ping(id=7) from 169.254.1.2
D: t+1.0s : [VirtualNode 169.254.1.3] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.1] Sending pong to 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPong) from 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.2] Received pong(id=2)}
D: t+1.0s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received ping from 169.254.1.3 pingTime=1
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPong) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] Received pong(id=5)}
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received ping from 169.254.1.1 pingTime=1
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpPing) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.3] Received ping(id=1000042) from 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.3] Sending pong to 169.254.1.1
D: t+1.0s : [VirtualNode 169.254.1.3] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPong) from 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] pingNeighborsRunnable: send ping to 169.254.1.2
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=4 sentTime=1699269619892
V: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPong) from 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.1] Received pong(id=3)}
W: t+1.0s : [OriginatingMessageManager for /169.254.1.1] : onPongReceived : pong from 169.254.1.3 does not match any known sent ping
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.3
V: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=5) from 169.254.1.3
D: t+1.0s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.2] Sending pong to 169.254.1.3
D: t+1.0s : [VirtualNode 169.254.1.2] Incoming packet received, but no socket listening on: 0
V: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpPong) from 169.254.1.2
V: t+1.0s : [VirtualNode 169.254.1.3] Received pong(id=8)}
V: t+1.0s : [OriginatingMessageManager for /169.254.1.3] received ping from 169.254.1.2 pingTime=1
V: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3
D: t+1.0s : [VirtualNode 169.254.1.3] Incoming packet received, but no socket listening on: 0
I: t+1.0s : [ChainSocketServer: 169.254.1.1] closed
D: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=4 hopCount=1 sentTime=1699269619892 Currently known: senttime=1699269618895 hop count = 1 isMoreRecentOrBetter=true
V: t+1.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+1.0s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1
I: t+1.0s : [ChainSocketServer: 169.254.1.2] closed
D: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
I: t+1.0s : [ChainSocketServer: 169.254.1.3] closed
D: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.3 ] : run : finished
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 57660 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.1] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 9046 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.2] init
D: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.3 ] Started on 28526 waiting for first packet
I: t+0.0s : [ChainSocketServer: 169.254.1.3] init
D: t+0.0s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:9046
D: t+0.0s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269619898 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269619899
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269619899 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269619899
D: t+0.0s : [VirtualNode 169.254.1.2] addNewNeighborConnection connection to virtual addr 169.254.1.3 via datagram to localhost/127.0.0.1:28526
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1
D: t+0.0s : [OriginatingMessageManager for /169.254.1.2] : addNeighbor - sending originating messages out
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269619899 Currently known: senttime=1699269619898 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1
V: t+0.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=2 hopCount=1 sentTime=1699269619900 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=1 sentTime=1699269619900
V: t+0.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=1 hopCount=1 sentTime=1699269619900 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1
V: t+0.0s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1
V: t+0.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269619900
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 messageId=1 hopCount=2 sentTime=1699269619900 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
V: t+0.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269619900 Currently known: senttime=1699269619900 hop count = 1 isMoreRecentOrBetter=false
D: t+0.0s : Drop mmcp packet from -1442971390
V: t+0.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269619900 Currently known: senttime=1699269619899 hop count = 1 isMoreRecentOrBetter=true
V: t+0.0s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3
I: t+0.17s : [ChainSocketServer: 169.254.1.1] closed
D: t+0.17s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished
I: t+0.17s : [ChainSocketServer: 169.254.1.2] closed
D: t+0.17s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished
I: t+0.17s : [ChainSocketServer: 169.254.1.3] closed
D: t+0.17s : [VirtualNodeDatagramSocket for 169.254.1.3 ] : run : finished
]]>