XV: t+0.04s : [VirtualDatagramSocketImpl] send packet size=1000 bytes to /0.0.0.43:6713 bV: t+0.01s : [VirtualDatagramSocketImpl] incoming virtual packet=1020 bytes from 0.0.0.43:31825 FV: t+0.0s : [VirtualDatagramSocketImpl] bind laddr=/0.0.0.42 lport=0 FV: t+0.0s : [VirtualDatagramSocketImpl] bind laddr=/0.0.0.43 lport=0 XV: t+0.0s : [VirtualDatagramSocketImpl] send packet size=1000 bytes to /0.0.0.43:41253 aV: t+0.01s : [VirtualDatagramSocketImpl] incoming virtual packet=1020 bytes from 0.0.0.42:9364 BD: t+0.0s : [UdpForwardRule : 60483 -> 127.0.0.1:39087] listening aD: t+0.0s : [VirtualNodeDatagramSocket for 0.0.0.42 ] Started on 56694 waiting for first packet aD: t+0.0s : [VirtualNodeDatagramSocket for 0.0.0.43 ] Started on 45996 waiting for first packet eD: t+0.09s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 14960 waiting for first packet 4I: t+0.09s : [ChainSocketServer: 169.254.1.1] init 4I: t+0.11s : [ChainSocketServer: 169.254.1.2] init eD: t+0.11s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 31675 waiting for first packet D: t+0.12s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:31675 kD: t+0.12s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out fV: t+0.13s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 yV: t+0.13s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 V: t+0.15s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269604969 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true {V: t+0.16s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1 zV: t+0.16s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269605000 fV: t+0.16s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 yV: t+0.16s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 V: t+0.16s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269605000 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true {V: t+0.16s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2 zV: t+0.16s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269605006 fV: t+0.16s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 yV: t+0.16s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 V: t+0.16s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269605006 Currently known: senttime=1699269604969 hop count = 1 isMoreRecentOrBetter=true {V: t+0.16s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1 KV: t+0.17s : [VirtualDatagramSocketImpl] bind laddr=/169.254.1.1 lport=81 KV: t+0.17s : [VirtualDatagramSocketImpl] bind laddr=/169.254.1.2 lport=82 WV: t+0.17s : [VirtualDatagramSocketImpl] send packet size=11 bytes to /169.254.1.2:82 `V: t+0.17s : [VirtualDatagramSocketImpl] incoming virtual packet=31 bytes from 169.254.1.1:81 6I: t+0.17s : [ChainSocketServer: 169.254.1.1] closed LD: t+0.17s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished 6I: t+0.17s : [ChainSocketServer: 169.254.1.2] closed LD: t+0.17s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished 6I: t+0.0s : [ChainSocketServer: 169.254.127.63] init gD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.127.63 ] Started on 11670 waiting for first packet iD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.112.234 ] Started on 24562 waiting for first packet 8I: t+0.01s : [ChainSocketServer: 169.254.112.234] init D: t+0.01s : [VirtualNode 169.254.127.63] addNewNeighborConnection connection to virtual addr 169.254.112.234 via datagram to localhost/127.0.0.1:24562 nD: t+0.01s : [OriginatingMessageManager for /169.254.127.63] : addNeighbor - sending originating messages out mV: t+0.01s : [VirtualNode 169.254.112.234] received MMCP message (MmcpOriginatorMessage) from 169.254.127.63 V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] received originating message from 169.254.127.63 via 169.254.127.63 V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] received originating message from 169.254.127.63 via 169.254.127.63 messageId=1 hopCount=1 sentTime=1699269605031 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] update originator messages: currently known nodes = 169.254.127.63 ~V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] sending originating message messageId=1 sentTime=1699269605032 mV: t+0.01s : [VirtualNode 169.254.127.63] received MMCP message (MmcpOriginatorMessage) from 169.254.112.234 V: t+0.01s : [OriginatingMessageManager for /169.254.127.63] received originating message from 169.254.112.234 via 169.254.112.234 V: t+0.01s : [OriginatingMessageManager for /169.254.127.63] received originating message from 169.254.112.234 via 169.254.112.234 messageId=1 hopCount=1 sentTime=1699269605032 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true V: t+0.01s : [OriginatingMessageManager for /169.254.127.63] update originator messages: currently known nodes = 169.254.112.234 }V: t+0.01s : [OriginatingMessageManager for /169.254.127.63] sending originating message messageId=2 sentTime=1699269605033 mV: t+0.01s : [VirtualNode 169.254.112.234] received MMCP message (MmcpOriginatorMessage) from 169.254.127.63 V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] received originating message from 169.254.127.63 via 169.254.127.63 V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] received originating message from 169.254.127.63 via 169.254.127.63 messageId=2 hopCount=1 sentTime=1699269605033 Currently known: senttime=1699269605031 hop count = 1 isMoreRecentOrBetter=true V: t+0.01s : [OriginatingMessageManager for /169.254.112.234] update originator messages: currently known nodes = 169.254.127.63 Connected node1 -> node2 `V: t+0.02s : [VirtualNode 169.254.112.234] received MMCP message (MmcpPing) from 169.254.127.63 ]V: t+0.02s : [VirtualNode 169.254.112.234] Received ping(id=-1407287034) from 169.254.127.63 JV: t+0.02s : [VirtualNode 169.254.112.234] Sending pong to 169.254.127.63 `V: t+0.02s : [VirtualNode 169.254.127.63] received MMCP message (MmcpPong) from 169.254.112.234 ?V: t+0.02s : [VirtualNode 169.254.127.63] Received pong(id=2)} W: t+0.02s : [OriginatingMessageManager for /169.254.127.63] : onPongReceived : pong from 169.254.112.234 does not match any known sent ping 9I: t+0.02s : [ChainSocketServer: 169.254.127.63] closed bD: t+0.02s : [VirtualNode 169.254.127.63] Incoming packet received, but no socket listening on: 0 OD: t+0.03s : [VirtualNodeDatagramSocket for 169.254.127.63 ] : run : finished :I: t+0.03s : [ChainSocketServer: 169.254.112.234] closed cD: t+0.03s : [VirtualNode 169.254.112.234] Incoming packet received, but no socket listening on: 0 PD: t+0.03s : [VirtualNodeDatagramSocket for 169.254.112.234 ] : run : finished 3I: t+0.0s : [ChainSocketServer: 169.254.1.1] init cD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 4871 waiting for first packet dD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 20686 waiting for first packet 4I: t+0.01s : [ChainSocketServer: 169.254.1.2] init D: t+0.01s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:20686 kD: t+0.01s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 yV: 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=1699269605059 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 zV: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269605060 fV: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 yV: 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=1699269605060 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 zV: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269605061 fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 yV: 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=1699269605061 Currently known: senttime=1699269605059 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 wI: t+0.05s : [ChainSocketFactoryImpl for /169.254.1.1] created socket to /169.254.1.2:36815 nexthop = /127.0.0.1:36815 6I: t+0.05s : [ChainSocketServer: 169.254.1.1] closed LD: t+0.05s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished 6I: t+0.06s : [ChainSocketServer: 169.254.1.2] closed LD: t+0.06s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished dD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 50204 waiting for first packet 3I: t+0.0s : [ChainSocketServer: 169.254.1.1] init dD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 35758 waiting for first packet 3I: t+0.0s : [ChainSocketServer: 169.254.1.2] init dD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.3 ] Started on 3380 waiting for first packet 4I: t+0.01s : [ChainSocketServer: 169.254.1.3] init D: t+0.01s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:35758 kD: t+0.01s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 yV: 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=1699269605126 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 zV: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269605127 fV: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 yV: 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=1699269605127 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 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:3380 kD: t+0.01s : [OriginatingMessageManager for /169.254.1.2] : addNeighbor - sending originating messages out zV: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269605129 fV: t+0.02s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 yV: t+0.02s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 V: t+0.02s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269605129 Currently known: senttime=1699269605126 hop count = 1 isMoreRecentOrBetter=true {V: t+0.02s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1 fV: t+0.02s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 yV: t+0.02s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 V: t+0.02s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=2 hopCount=1 sentTime=1699269605129 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true {V: t+0.02s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2 zV: t+0.02s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=1 sentTime=1699269605132 fV: t+0.02s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3 yV: t+0.02s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 V: t+0.02s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=1 hopCount=1 sentTime=1699269605132 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true V: t+0.02s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1 zV: t+0.02s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269605136 fV: t+0.02s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 yV: t+0.02s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 V: t+0.02s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269605136 Currently known: senttime=1699269605127 hop count = 1 isMoreRecentOrBetter=true {V: t+0.02s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2 fV: t+0.03s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 yV: t+0.03s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 V: t+0.03s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269605136 Currently known: senttime=1699269605129 hop count = 1 isMoreRecentOrBetter=true {V: t+0.03s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2 qV: t+0.03s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1 fV: t+0.03s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3 yV: t+0.03s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 V: t+0.03s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 messageId=1 hopCount=2 sentTime=1699269605132 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true V: t+0.03s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3 yV: t+1.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=3 sentTime=1699269606111 eV: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 xV: 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=1699269606111 Currently known: senttime=1699269605129 hop count = 1 isMoreRecentOrBetter=true jV: 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.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1 pV: 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 XV: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.1 KV: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=4) from 169.254.1.1 eV: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 xV: 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=1699269606111 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 yV: t+1.0s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=4 sentTime=1699269606113 eV: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 xV: 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=1699269606113 Currently known: senttime=1699269605136 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 jV: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.3 jV: t+1.0s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.1 eV: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 xV: 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=1699269606113 Currently known: senttime=1699269605136 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, 169.254.1.3 XV: t+1.0s : [VirtualNode 169.254.1.3] received MMCP message (MmcpPing) from 169.254.1.2 KV: t+1.0s : [VirtualNode 169.254.1.3] Received ping(id=6) from 169.254.1.2 BV: t+1.0s : [VirtualNode 169.254.1.3] Sending pong to 169.254.1.2 XV: t+1.0s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPing) from 169.254.1.2 KV: t+1.0s : [VirtualNode 169.254.1.1] Received ping(id=7) from 169.254.1.2 BV: 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 KD: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished 5I: t+1.0s : [ChainSocketServer: 169.254.1.1] closed BV: 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 KD: t+1.0s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished zV: t+1.01s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=3 sentTime=1699269606120 ^D: t+1.0s : [VirtualNode 169.254.1.3] Incoming packet received, but no socket listening on: 0 5I: t+1.0s : [ChainSocketServer: 169.254.1.2] closed kV: t+1.01s : [OriginatingMessageManager for /169.254.1.3] pingNeighborsRunnable: send ping to 169.254.1.2 6I: t+1.02s : [ChainSocketServer: 169.254.1.3] closed  LD: t+1.02s : [VirtualNodeDatagramSocket for 169.254.1.3 ] : run : finished  4I: t+0.01s : [ChainSocketServer: 169.254.1.1] init  eD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 52077 waiting for first packet  eD: t+0.02s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 48866 waiting for first packet  4I: t+0.02s : [ChainSocketServer: 169.254.1.2] init  eD: t+0.03s : [VirtualNodeDatagramSocket for 169.254.1.3 ] Started on 55066 waiting for first packet  4I: t+0.03s : [ChainSocketServer: 169.254.1.3] init  D: t+0.03s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:48866  kD: t+0.03s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out  fV: t+0.03s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1  yV: t+0.03s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1  V: t+0.03s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=1 hopCount=1 sentTime=1699269606168 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true  {V: t+0.03s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1  zV: t+0.03s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269606169  fV: t+0.03s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2  yV: t+0.03s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2  V: t+0.03s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=1 hopCount=1 sentTime=1699269606169 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true  {V: t+0.03s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2  zV: t+0.03s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269606170  D: t+0.03s : [VirtualNode 169.254.1.2] addNewNeighborConnection connection to virtual addr 169.254.1.3 via datagram to localhost/127.0.0.1:55066  kD: t+0.03s : [OriginatingMessageManager for /169.254.1.2] : addNeighbor - sending originating messages out  fV: t+0.03s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1  yV: t+0.03s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1  V: t+0.03s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.1 via 169.254.1.1 messageId=2 hopCount=1 sentTime=1699269606170 Currently known: senttime=1699269606168 hop count = 1 isMoreRecentOrBetter=true  fV: t+0.03s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2  yV: t+0.03s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2  V: t+0.04s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=2 hopCount=1 sentTime=1699269606171 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true  {V: t+0.04s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2  {V: t+0.03s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1  zV: t+0.04s : [OriginatingMessageManager for /169.254.1.3] sending originating message messageId=1 sentTime=1699269606172  fV: t+0.04s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3  yV: t+0.04s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3  V: t+0.04s : [OriginatingMessageManager for /169.254.1.2] received originating message from 169.254.1.3 via 169.254.1.3 messageId=1 hopCount=1 sentTime=1699269606172 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true  V: t+0.04s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.3, 169.254.1.1  qV: t+0.04s : [VirtualNode 169.254.1.2] broadcast packet from=169.254.1.3 lasthop=169.254.1.3 send to 169.254.1.1  fV: t+0.04s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.3  yV: t+0.04s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2  V: t+0.04s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.3 via 169.254.1.2 messageId=1 hopCount=2 sentTime=1699269606172 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true  V: t+0.04s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3  zV: t+0.04s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269606175  fV: t+0.04s : [VirtualNode 169.254.1.3] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2  yV: t+0.04s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2  V: t+0.04s : [OriginatingMessageManager for /169.254.1.3] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269606175 Currently known: senttime=1699269606171 hop count = 1 isMoreRecentOrBetter=true  {V: t+0.04s : [OriginatingMessageManager for /169.254.1.3] update originator messages: currently known nodes = 169.254.1.2  fV: t+0.04s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2  yV: t+0.04s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2  V: t+0.04s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 messageId=3 hopCount=1 sentTime=1699269606175 Currently known: senttime=1699269606169 hop count = 1 isMoreRecentOrBetter=true  V: t+0.04s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2, 169.254.1.3  CD: t+0.05s : [ChainSocketServer: 169.254.1.2] accepted new client  P/127.0.0.1:48866 is not final destination - write init request and get response  hD: t+0.05s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : init client - reading init request...  xD: t+0.05s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : receive init request to connect to /169.254.1.3:33315  wI: t+0.05s : [ChainSocketFactoryImpl for /169.254.1.2] created socket to /169.254.1.3:33315 nexthop = /127.0.0.1:33315  XD: t+0.05s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : created onward socket  \D: t+0.05s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : wrote chain init response  #/127.0.0.1:48866 got init response  wI: t+0.05s : [ChainSocketFactoryImpl for /169.254.1.1] created socket to /169.254.1.3:33315 nexthop = /127.0.0.1:48866  V: t+0.05s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : CopyStream: onwardToIncoming - start copying input to output  V: t+0.05s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : CopyStream: incomingToOnward - start copying input to output  V: t+0.06s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050 : CopyStream: onwardToIncoming - finished copying - reached end of stream  6I: t+0.06s : [ChainSocketServer: 169.254.1.1] closed  LD: t+0.06s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished  6I: t+0.06s : [ChainSocketServer: 169.254.1.2] closed  LD: t+0.06s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished  LD: t+0.06s : [VirtualNodeDatagramSocket for 169.254.1.3 ] : run : finished  6I: t+0.06s : [ChainSocketServer: 169.254.1.3] closed !~W: t+0.06s : [ChainSocketServer: 169.254.1.2] /127.0.0.1:51050: CopyStream: aborting java.net.SocketException: Socket closed !G at java.base/sun.nio.ch.NioSocketImpl.endRead(NioSocketImpl.java:248) !H at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:327) !D at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350) !F at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803) !F at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966) != at java.base/java.io.InputStream.read(InputStream.java:218) !5 at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106) != at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103) !n at com.ustadmobile.meshrabiya.vnet.socket.ChainSocketServer$CopyStreamRunnable.run(ChainSocketServer.kt:144) !V at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) !G 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) !4 at java.base/java.lang.Thread.run(Thread.java:833) ! !hD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.102.132 ] Started on 28097 waiting for first packet !7I: t+0.0s : [ChainSocketServer: 169.254.102.132] init !hD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.81.133 ] Started on 41110 waiting for first packet !7I: t+0.01s : [ChainSocketServer: 169.254.81.133] init !D: t+0.01s : [VirtualNode 169.254.102.132] addNewNeighborConnection connection to virtual addr 169.254.81.133 via datagram to localhost/127.0.0.1:41110 !oD: t+0.01s : [OriginatingMessageManager for /169.254.102.132] : addNeighbor - sending originating messages out !mV: t+0.01s : [VirtualNode 169.254.81.133] received MMCP message (MmcpOriginatorMessage) from 169.254.102.132 !V: t+0.01s : [OriginatingMessageManager for /169.254.81.133] received originating message from 169.254.102.132 via 169.254.102.132 !V: t+0.01s : [OriginatingMessageManager for /169.254.81.133] received originating message from 169.254.102.132 via 169.254.102.132 messageId=1 hopCount=1 sentTime=1699269606214 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true !V: t+0.01s : [OriginatingMessageManager for /169.254.81.133] update originator messages: currently known nodes = 169.254.102.132 !}V: t+0.01s : [OriginatingMessageManager for /169.254.81.133] sending originating message messageId=1 sentTime=1699269606216 !mV: t+0.01s : [VirtualNode 169.254.102.132] received MMCP message (MmcpOriginatorMessage) from 169.254.81.133 !V: t+0.01s : [OriginatingMessageManager for /169.254.102.132] received originating message from 169.254.81.133 via 169.254.81.133 !V: t+0.01s : [OriginatingMessageManager for /169.254.102.132] received originating message from 169.254.81.133 via 169.254.81.133 messageId=1 hopCount=1 sentTime=1699269606216 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true !V: t+0.01s : [OriginatingMessageManager for /169.254.102.132] update originator messages: currently known nodes = 169.254.81.133 !~V: t+0.01s : [OriginatingMessageManager for /169.254.102.132] sending originating message messageId=2 sentTime=1699269606217 !mV: t+0.02s : [VirtualNode 169.254.81.133] received MMCP message (MmcpOriginatorMessage) from 169.254.102.132 !V: t+0.02s : [OriginatingMessageManager for /169.254.81.133] received originating message from 169.254.102.132 via 169.254.102.132 !V: t+0.02s : [OriginatingMessageManager for /169.254.81.133] received originating message from 169.254.102.132 via 169.254.102.132 messageId=2 hopCount=1 sentTime=1699269606217 Currently known: senttime=1699269606214 hop count = 1 isMoreRecentOrBetter=true !V: t+0.02s : [OriginatingMessageManager for /169.254.81.133] update originator messages: currently known nodes = 169.254.102.132 !jV: t+0.02s : [VirtualNode 169.254.102.132] received MMCP message (MmcpHotspotRequest) from 169.254.81.133 !TI: t+0.02s : [VirtualNode 169.254.102.132] Received hotspotrequest (id=-1006537128) !cD: t+0.02s : [VirtualNode 169.254.102.132] Incoming packet received, but no socket listening on: 0 !UI: t+0.02s : [VirtualNode 169.254.102.132] sending hotspotresponse to 169.254.81.133 !kV: t+0.02s : [VirtualNode 169.254.81.133] received MMCP message (MmcpHotspotResponse) from 169.254.102.132 !bD: t+0.02s : [VirtualNode 169.254.81.133] Incoming packet received, but no socket listening on: 0 !PD: t+0.02s : [VirtualNodeDatagramSocket for 169.254.102.132 ] : run : finished !:I: t+0.02s : [ChainSocketServer: 169.254.102.132] closed !9I: t+0.02s : [ChainSocketServer: 169.254.81.133] closed !OD: t+0.02s : [VirtualNodeDatagramSocket for 169.254.81.133 ] : run : finished "cD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 6233 waiting for first packet "3I: t+0.0s : [ChainSocketServer: 169.254.1.1] init "4I: t+0.01s : [ChainSocketServer: 169.254.1.2] init "eD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 65398 waiting for first packet "D: t+0.01s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:65398 "kD: t+0.01s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out "fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 "yV: 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=1699269606236 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 "zV: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269606237 "fV: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 "yV: 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=1699269606237 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 "zV: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269606239 "fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 "yV: 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=1699269606239 Currently known: senttime=1699269606236 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 "DD: t+0.01s : [UdpForwardRule : 60983 -> 169.254.1.2:8000] listening "MV: t+0.01s : [VirtualDatagramSocketImpl] bind laddr=/169.254.1.2 lport=8000 "BD: t+0.01s : [UdpForwardRule : 8000 -> 127.0.0.1:53362] listening ")Send packet to localhost/127.0.0.1:60983 "JV: t+0.01s : [VirtualDatagramSocketImpl] bind laddr=/169.254.1.1 lport=0 "XV: t+0.01s : [VirtualDatagramSocketImpl] send packet size=5 bytes to /169.254.1.2:8000 "cV: t+0.01s : [VirtualDatagramSocketImpl] incoming virtual packet=25 bytes from 169.254.1.1:25602 "YV: t+0.01s : [VirtualDatagramSocketImpl] send packet size=5 bytes to /169.254.1.1:25602 "bV: t+0.01s : [VirtualDatagramSocketImpl] incoming virtual packet=25 bytes from 169.254.1.2:8000 "6I: t+0.01s : [ChainSocketServer: 169.254.1.1] closed "6I: t+0.01s : [ChainSocketServer: 169.254.1.2] closed "LD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.1 ] : run : finished LD: t+0.02s : [VirtualNodeDatagramSocket for 169.254.1.2 ] : run : finished #gD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.67.161 ] Started on 52950 waiting for first packet #6I: t+0.0s : [ChainSocketServer: 169.254.67.161] init #hD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.15.238 ] Started on 30418 waiting for first packet #7I: t+0.01s : [ChainSocketServer: 169.254.15.238] init #D: t+0.01s : [VirtualNode 169.254.15.238] addNewNeighborConnection connection to virtual addr 169.254.67.161 via datagram to localhost/127.0.0.1:52950 #nD: t+0.01s : [OriginatingMessageManager for /169.254.15.238] : addNeighbor - sending originating messages out #lV: t+0.01s : [VirtualNode 169.254.67.161] received MMCP message (MmcpOriginatorMessage) from 169.254.15.238 #V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.15.238 via 169.254.15.238 #V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.15.238 via 169.254.15.238 messageId=1 hopCount=1 sentTime=1699269606257 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] update originator messages: currently known nodes = 169.254.15.238 #}V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] sending originating message messageId=1 sentTime=1699269606258 #lV: t+0.01s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.67.161 #V: t+0.01s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.67.161 via 169.254.67.161 #V: t+0.01s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.67.161 via 169.254.67.161 messageId=1 hopCount=1 sentTime=1699269606258 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.01s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.67.161 #}V: t+0.01s : [OriginatingMessageManager for /169.254.15.238] sending originating message messageId=2 sentTime=1699269606259 #lV: t+0.01s : [VirtualNode 169.254.67.161] received MMCP message (MmcpOriginatorMessage) from 169.254.15.238 #V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.15.238 via 169.254.15.238 #V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.15.238 via 169.254.15.238 messageId=2 hopCount=1 sentTime=1699269606259 Currently known: senttime=1699269606257 hop count = 1 isMoreRecentOrBetter=true #V: t+0.01s : [OriginatingMessageManager for /169.254.67.161] update originator messages: currently known nodes = 169.254.15.238 #gD: t+0.02s : [VirtualNodeDatagramSocket for 169.254.3.194 ] Started on 17309 waiting for first packet #6I: t+0.02s : [ChainSocketServer: 169.254.3.194] init #D: t+0.02s : [VirtualNode 169.254.3.194] addNewNeighborConnection connection to virtual addr 169.254.67.161 via datagram to localhost/127.0.0.1:52950 #mD: t+0.02s : [OriginatingMessageManager for /169.254.3.194] : addNeighbor - sending originating messages out #kV: t+0.02s : [VirtualNode 169.254.67.161] received MMCP message (MmcpOriginatorMessage) from 169.254.3.194 #V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.3.194 via 169.254.3.194 #V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.3.194 via 169.254.3.194 messageId=1 hopCount=1 sentTime=1699269606269 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] update originator messages: currently known nodes = 169.254.15.238, 169.254.3.194 #{V: t+0.02s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.3.194 lasthop=169.254.3.194 send to 169.254.15.238 #kV: t+0.02s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.3.194 #}V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] sending originating message messageId=2 sentTime=1699269606270 #kV: t+0.02s : [VirtualNode 169.254.3.194] received MMCP message (MmcpOriginatorMessage) from 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.67.161 via 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.67.161 via 169.254.67.161 messageId=2 hopCount=1 sentTime=1699269606270 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.02s : [OriginatingMessageManager for /169.254.3.194] update originator messages: currently known nodes = 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.3.194 via 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.3.194 via 169.254.67.161 messageId=1 hopCount=2 sentTime=1699269606269 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.3.194, 169.254.67.161 #lV: t+0.02s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.67.161 via 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.67.161 via 169.254.67.161 messageId=2 hopCount=1 sentTime=1699269606270 Currently known: senttime=1699269606258 hop count = 1 isMoreRecentOrBetter=true #|V: t+0.02s : [OriginatingMessageManager for /169.254.3.194] sending originating message messageId=2 sentTime=1699269606272 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.3.194, 169.254.67.161 #kV: t+0.02s : [VirtualNode 169.254.67.161] received MMCP message (MmcpOriginatorMessage) from 169.254.3.194 #V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.3.194 via 169.254.3.194 #V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.3.194 via 169.254.3.194 messageId=2 hopCount=1 sentTime=1699269606272 Currently known: senttime=1699269606269 hop count = 1 isMoreRecentOrBetter=true #V: t+0.02s : [OriginatingMessageManager for /169.254.67.161] update originator messages: currently known nodes = 169.254.15.238, 169.254.3.194 #{V: t+0.02s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.3.194 lasthop=169.254.3.194 send to 169.254.15.238 #kV: t+0.02s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.3.194 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.3.194 via 169.254.67.161 #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.3.194 via 169.254.67.161 messageId=2 hopCount=2 sentTime=1699269606272 Currently known: senttime=1699269606269 hop count = 2 isMoreRecentOrBetter=true #V: t+0.02s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.3.194, 169.254.67.161 #hD: t+0.02s : [VirtualNodeDatagramSocket for 169.254.91.226 ] Started on 29922 waiting for first packet #7I: t+0.02s : [ChainSocketServer: 169.254.91.226] init #D: t+0.02s : [VirtualNode 169.254.91.226] addNewNeighborConnection connection to virtual addr 169.254.67.161 via datagram to localhost/127.0.0.1:52950 #nD: t+0.02s : [OriginatingMessageManager for /169.254.91.226] : addNeighbor - sending originating messages out #lV: t+0.03s : [VirtualNode 169.254.67.161] received MMCP message (MmcpOriginatorMessage) from 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.91.226 via 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.91.226 via 169.254.91.226 messageId=1 hopCount=1 sentTime=1699269606276 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] update originator messages: currently known nodes = 169.254.15.238, 169.254.3.194, 169.254.91.226 #}V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] sending originating message messageId=3 sentTime=1699269606276 #}V: t+0.03s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.91.226 lasthop=169.254.91.226 send to 169.254.15.238 #lV: t+0.03s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.67.161 via 169.254.67.161 #kV: t+0.03s : [VirtualNode 169.254.3.194] received MMCP message (MmcpOriginatorMessage) from 169.254.67.161 #|V: t+0.03s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.91.226 lasthop=169.254.91.226 send to 169.254.3.194 #lV: t+0.03s : [VirtualNode 169.254.91.226] received MMCP message (MmcpOriginatorMessage) from 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.67.161 via 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.67.161 via 169.254.67.161 messageId=3 hopCount=1 sentTime=1699269606276 Currently known: senttime=1699269606270 hop count = 1 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.91.226] received originating message from 169.254.67.161 via 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.67.161 via 169.254.67.161 messageId=3 hopCount=1 sentTime=1699269606276 Currently known: senttime=1699269606270 hop count = 1 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.91.226] received originating message from 169.254.67.161 via 169.254.67.161 messageId=3 hopCount=1 sentTime=1699269606276 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.3.194, 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] update originator messages: currently known nodes = 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.91.226] update originator messages: currently known nodes = 169.254.67.161 #lV: t+0.03s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.91.226 via 169.254.67.161 #kV: t+0.03s : [VirtualNode 169.254.3.194] received MMCP message (MmcpOriginatorMessage) from 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.91.226 via 169.254.67.161 messageId=1 hopCount=2 sentTime=1699269606276 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.91.226 via 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.3.194, 169.254.91.226, 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.91.226 via 169.254.67.161 messageId=1 hopCount=2 sentTime=1699269606276 Currently known: senttime=0 hop count = 127 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] update originator messages: currently known nodes = 169.254.91.226, 169.254.67.161 #}V: t+0.03s : [OriginatingMessageManager for /169.254.91.226] sending originating message messageId=2 sentTime=1699269606278 #lV: t+0.03s : [VirtualNode 169.254.67.161] received MMCP message (MmcpOriginatorMessage) from 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.91.226 via 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] received originating message from 169.254.91.226 via 169.254.91.226 messageId=2 hopCount=1 sentTime=1699269606278 Currently known: senttime=1699269606276 hop count = 1 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.67.161] update originator messages: currently known nodes = 169.254.15.238, 169.254.3.194, 169.254.91.226 #}V: t+0.03s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.91.226 lasthop=169.254.91.226 send to 169.254.15.238 #vV: t+0.03s : [VirtualNode 169.254.15.238] broadcast packet from=169.254.15.238 lasthop=0.0.0.0 send to 169.254.67.161 #|V: t+0.03s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.91.226 lasthop=169.254.91.226 send to 169.254.3.194 #kV: t+0.03s : [VirtualNode 169.254.3.194] received MMCP message (MmcpOriginatorMessage) from 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.91.226 via 169.254.67.161 #_V: t+0.03s : [VirtualNode 169.254.67.161] received MMCP message (MmcpPing) from 169.254.15.238 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] received originating message from 169.254.91.226 via 169.254.67.161 messageId=2 hopCount=2 sentTime=1699269606278 Currently known: senttime=1699269606276 hop count = 2 isMoreRecentOrBetter=true #|V: t+0.03s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.15.238 lasthop=169.254.15.238 send to 169.254.3.194 #V: t+0.03s : [OriginatingMessageManager for /169.254.3.194] update originator messages: currently known nodes = 169.254.91.226, 169.254.67.161 #}V: t+0.03s : [VirtualNode 169.254.67.161] broadcast packet from=169.254.15.238 lasthop=169.254.15.238 send to 169.254.91.226 #^V: t+0.03s : [VirtualNode 169.254.3.194] received MMCP message (MmcpPing) from 169.254.15.238 #_V: t+0.03s : [VirtualNode 169.254.91.226] received MMCP message (MmcpPing) from 169.254.15.238 #9I: t+0.03s : [ChainSocketServer: 169.254.67.161] closed #OD: t+0.03s : [VirtualNodeDatagramSocket for 169.254.67.161 ] : run : finished #9I: t+0.03s : [ChainSocketServer: 169.254.15.238] closed #lV: t+0.03s : [VirtualNode 169.254.15.238] received MMCP message (MmcpOriginatorMessage) from 169.254.91.226 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.91.226 via 169.254.67.161 #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] received originating message from 169.254.91.226 via 169.254.67.161 messageId=2 hopCount=2 sentTime=1699269606278 Currently known: senttime=1699269606276 hop count = 2 isMoreRecentOrBetter=true #V: t+0.03s : [OriginatingMessageManager for /169.254.15.238] update originator messages: currently known nodes = 169.254.3.194, 169.254.91.226, 169.254.67.161 #OD: t+0.03s : [VirtualNodeDatagramSocket for 169.254.15.238 ] : run : finished #8I: t+0.03s : [ChainSocketServer: 169.254.3.194] closed #ND: t+0.03s : [VirtualNodeDatagramSocket for 169.254.3.194 ] : run : finished #9I: t+0.03s : [ChainSocketServer: 169.254.91.226] closed #OD: t+0.03s : [VirtualNodeDatagramSocket for 169.254.91.226 ] : run : finished $dD: t+0.0s : [VirtualNodeDatagramSocket for 169.254.1.1 ] Started on 64341 waiting for first packet $3I: t+0.0s : [ChainSocketServer: 169.254.1.1] init $eD: t+0.01s : [VirtualNodeDatagramSocket for 169.254.1.2 ] Started on 35679 waiting for first packet $4I: t+0.01s : [ChainSocketServer: 169.254.1.2] init $)Test node1=169.254.1.1 node2=169.254.1.2 $D: t+0.01s : [VirtualNode 169.254.1.1] addNewNeighborConnection connection to virtual addr 169.254.1.2 via datagram to localhost/127.0.0.1:35679 $kD: t+0.01s : [OriginatingMessageManager for /169.254.1.1] : addNeighbor - sending originating messages out $fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 $yV: 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=1699269606296 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 $zV: t+0.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=1 sentTime=1699269606296 $fV: t+0.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 $yV: 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=1699269606296 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 $zV: t+0.01s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=2 sentTime=1699269606297 $fV: t+0.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 $yV: 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=1699269606297 Currently known: senttime=1699269606296 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 $yV: t+1.0s : [OriginatingMessageManager for /169.254.1.1] sending originating message messageId=3 sentTime=1699269607284 $eV: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpOriginatorMessage) from 169.254.1.1 $xV: 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=1699269607284 Currently known: senttime=1699269606297 hop count = 1 isMoreRecentOrBetter=true $zV: t+1.0s : [OriginatingMessageManager for /169.254.1.2] update originator messages: currently known nodes = 169.254.1.1 $jV: t+1.0s : [OriginatingMessageManager for /169.254.1.1] pingNeighborsRunnable: send ping to 169.254.1.2 $XV: t+1.0s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPing) from 169.254.1.1 $KV: t+1.0s : [VirtualNode 169.254.1.2] Received ping(id=4) from 169.254.1.1 $BV: 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 $XV: 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.1] Received pong(id=2)} $dV: 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 $zV: t+1.01s : [OriginatingMessageManager for /169.254.1.2] sending originating message messageId=3 sentTime=1699269607293 $fV: t+1.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpOriginatorMessage) from 169.254.1.2 $yV: t+1.01s : [OriginatingMessageManager for /169.254.1.1] received originating message from 169.254.1.2 via 169.254.1.2 $V: t+1.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=1699269607293 Currently known: senttime=1699269606296 hop count = 1 isMoreRecentOrBetter=true ${V: t+1.01s : [OriginatingMessageManager for /169.254.1.1] update originator messages: currently known nodes = 169.254.1.2 $kV: t+1.01s : [OriginatingMessageManager for /169.254.1.2] pingNeighborsRunnable: send ping to 169.254.1.1 $YV: t+1.01s : [VirtualNode 169.254.1.1] received MMCP message (MmcpPing) from 169.254.1.2 $LV: t+1.01s : [VirtualNode 169.254.1.1] Received ping(id=4) from 169.254.1.2 $CV: t+1.01s : [VirtualNode 169.254.1.1] Sending pong to 169.254.1.2 $_D: t+1.01s : [VirtualNode 169.254.1.1] Incoming packet received, but no socket listening on: 0 $YV: t+1.01s : [VirtualNode 169.254.1.2] received MMCP message (MmcpPong) from 169.254.1.1 $D: t+0.0s : [ChainSocketServer: server1] accepted new client 24cD: t+0.0s : [ChainSocketServer: server1] /127.0.0.1:39330 : init client - reading init request... 24vD: t+0.0s : [ChainSocketServer: server1] /127.0.0.1:39330 : receive init request to connect to /169.254.76.190:45611 24>D: t+0.0s : [ChainSocketServer: server2] accepted new client 24Ylocalhost/127.0.0.1:37341 is not final destination - write init request and get response 24cD: t+0.0s : [ChainSocketServer: server2] /127.0.0.1:59810 : init client - reading init request... 24vD: t+0.0s : [ChainSocketServer: server2] /127.0.0.1:59810 : receive init request to connect to /169.254.76.190:45611 24I: t+0.01s : [ChainSocketFactoryImpl for /169.254.66.4] created socket to /169.254.76.190:45611 nexthop = localhost/127.0.0.1:45611 24TD: t+0.01s : [ChainSocketServer: server2] /127.0.0.1:59810 : created onward socket 24,localhost/127.0.0.1:37341 got init response 24I: t+0.01s : [ChainSocketFactoryImpl for /169.254.19.216] created socket to /169.254.76.190:45611 nexthop = localhost/127.0.0.1:37341 24TD: t+0.01s : [ChainSocketServer: server1] /127.0.0.1:39330 : created onward socket 24XD: t+0.01s : [ChainSocketServer: server1] /127.0.0.1:39330 : wrote chain init response 24XD: t+0.01s : [ChainSocketServer: server2] /127.0.0.1:59810 : wrote chain init response 24{V: t+0.01s : [ChainSocketServer: server1] /127.0.0.1:39330 : CopyStream: onwardToIncoming - start copying input to output 24{V: t+0.01s : [ChainSocketServer: server1] /127.0.0.1:39330 : CopyStream: incomingToOnward - start copying input to output 24{V: t+0.01s : [ChainSocketServer: server2] /127.0.0.1:59810 : CopyStream: onwardToIncoming - start copying input to output 24{V: t+0.01s : [ChainSocketServer: server2] /127.0.0.1:59810 : CopyStream: incomingToOnward - start copying input to output 24V: t+0.01s : [ChainSocketServer: server2] /127.0.0.1:59810 : CopyStream: onwardToIncoming - finished copying - reached end of stream 24V: t+0.01s : [ChainSocketServer: server1] /127.0.0.1:39330 : CopyStream: onwardToIncoming - finished copying - reached end of stream 24zW: t+0.01s : [ChainSocketServer: server1] /127.0.0.1:39330: CopyStream: aborting java.net.SocketException: Socket closed 24G at java.base/sun.nio.ch.NioSocketImpl.endRead(NioSocketImpl.java:248) 24H at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:327) 24D at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350) 24F at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803) 24F at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966) 24= at java.base/java.io.InputStream.read(InputStream.java:218) 245 at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106) 24= at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103) 24n at com.ustadmobile.meshrabiya.vnet.socket.ChainSocketServer$CopyStreamRunnable.run(ChainSocketServer.kt:144) 24V at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) 24G at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) 24^ at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) 24^ at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) 244 at java.base/java.lang.Thread.run(Thread.java:833) 24 24zW: t+0.01s : [ChainSocketServer: server2] /127.0.0.1:59810: CopyStream: aborting java.net.SocketException: Socket closed 24G at java.base/sun.nio.ch.NioSocketImpl.endRead(NioSocketImpl.java:248) 24H at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:327) 24D at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350) 24F at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803) 24F at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966) 24= at java.base/java.io.InputStream.read(InputStream.java:218) 245 at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106) 24= at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103) 24n at com.ustadmobile.meshrabiya.vnet.socket.ChainSocketServer$CopyStreamRunnable.run(ChainSocketServer.kt:144) 24V at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) 24G at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) 24^ at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) 24^ at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) 244 at java.base/java.lang.Thread.run(Thread.java:833) 24 242I: t+0.02s : [ChainSocketServer: server1] closed 242I: t+0.02s : [ChainSocketServer: server2] closed