View Issue Details

IDProjectCategoryView StatusLast Update
0002446GNUnettransport servicepublic2024-05-03 13:58
ReporterLRN Assigned ToLRN  
PrioritynormalSeveritymajorReproducibilitysometimes
Status closedResolutionfixed 
Product VersionGit master 
Target Version0.9.4Fixed in Version0.9.4 
Summary0002446: Assertion failed at plugin_transport_udp.c:1145
Descriptionif (GNUNET_YES != GNUNET_CONTAINER_multihashmap_contains_value(plugin->sessions, &s->target.hashPubKey, s)) test fails in udp_plugin_send()
Steps To ReproduceRun mesh 2d torus test enough times
Additional InformationI've added an extra log line to highlight the failure. It's logged right before GNUNET_break (0);
июн 21 13:29:06-00000000000159929673 transport-udp-4912 DEBUG Message for peer `JP32' (366 bytes) is not delayed
июн 21 13:29:06-00000000000159929673 transport-udp-4912 DEBUG UDP transmitted 366-byte message to `169.254.92.128:12297' (366: ok)
июн 21 13:29:06-00000000000159929673 transport-udp-4912 DEBUG Calling continuation for 366 byte message to `JP32' with result OK
июн 21 13:29:06-00000000000159929677 transport-udp-4912 DEBUG Message for peer `JP32' (506 bytes) is not delayed
июн 21 13:29:06-00000000000159929677 transport-udp-4912 DEBUG UDP transmitted 506-byte message to `169.254.92.128:12297' (506: ok)
июн 21 13:29:06-00000000000159929677 transport-udp-4912 DEBUG Calling continuation for 506 byte message to `JP32' with result OK
июн 21 13:29:06-00000000000159929701 transport-udp-4912 DEBUG UDP received 366(366)-byte message from `169.254.92.128:12297' type 56
июн 21 13:29:06-00000000000159929701 transport-udp-4912 DEBUG Received message with 366 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:29:06-00000000000159929701 transport-udp-4912 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297'
июн 21 13:29:06-00000000000159929701 transport-udp-4912 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:29:06-00000000000159929701 transport-udp-4912 DEBUG Found existing session 0x1f3f358
июн 21 13:29:06-00000000000159929701 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 set to 300000
июн 21 13:29:07-00000000000159930636 transport-udp-4912 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:29:07-00000000000159930636 transport-udp-4912 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930636 transport-udp-4912 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930636 transport-udp-4912 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:29:07-00000000000159930636 transport-udp-4912 DEBUG Found existing session 0x1f3f358
июн 21 13:29:07-00000000000159930636 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 set to 300000
июн 21 13:29:07-00000000000159930639 transport-udp-4912 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:29:07-00000000000159930639 transport-udp-4912 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930639 transport-udp-4912 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930639 transport-udp-4912 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:29:07-00000000000159930639 transport-udp-4912 DEBUG Found existing session 0x1f3f358
июн 21 13:29:07-00000000000159930639 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 set to 300000
июн 21 13:29:07-00000000000159930640 transport-udp-4912 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:29:07-00000000000159930640 transport-udp-4912 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930640 transport-udp-4912 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930640 transport-udp-4912 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:29:07-00000000000159930641 transport-udp-4912 DEBUG Found existing session 0x1f3f358
июн 21 13:29:07-00000000000159930641 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 set to 300000
июн 21 13:29:07-00000000000159930645 transport-udp-4912 DEBUG UDP transmits 88-byte message to `JP32' using address `169.254.92.128:12297'
июн 21 13:29:07-00000000000159930645 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 set to 300000
июн 21 13:29:07-00000000000159930645 transport-udp-4912 DEBUG Message for peer `JP32' (88 bytes) is not delayed
июн 21 13:29:07-00000000000159930645 transport-udp-4912 DEBUG UDP transmitted 88-byte message to `169.254.92.128:12297' (88: ok)
июн 21 13:29:07-00000000000159930645 transport-udp-4912 DEBUG Calling continuation for 88 byte message to `JP32' with result OK
июн 21 13:29:08-00000000000159931421 transport-udp-4912 DEBUG UDP transmits 616-byte message to `JP32' using address `169.254.92.128:12297'
июн 21 13:29:08-00000000000159931421 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 set to 300000
июн 21 13:29:08-00000000000159931421 transport-udp-4912 DEBUG Message for peer `JP32' (616 bytes) is not delayed
июн 21 13:29:08-00000000000159931421 transport-udp-4912 DEBUG UDP transmitted 616-byte message to `169.254.92.128:12297' (616: ok)
июн 21 13:29:08-00000000000159931421 transport-udp-4912 DEBUG Calling continuation for 616 byte message to `JP32' with result OK
июн 21 13:29:08-00000000000159931421 transport-udp-4912 DEBUG Disconnecting from peer `JP32'
июн 21 13:29:08-00000000000159931421 transport-udp-4912 DEBUG Session 0x1f3f358 to peer `JP32' address ended
июн 21 13:29:08-00000000000159931421 transport-4912 DEBUG Timeout rescheduled for session 0x1f3f358 canceled
июн 21 13:29:08-00000000000159931436 transport-udp-4912 DEBUG UDP received 616(616)-byte message from `169.254.92.128:12297' type 56
июн 21 13:29:08-00000000000159931436 transport-udp-4912 DEBUG Received message with 616 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:29:08-00000000000159931436 transport-udp-4912 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297'
июн 21 13:29:08-00000000000159931436 transport-4912 DEBUG Timeout for session 0x1f445e8 set to 300000
июн 21 13:29:08-00000000000159931436 transport-udp-4912 DEBUG Creating new session 0x1f445e8 for peer `JP32' address `169.254.92.128:12297'
июн 21 13:29:08-00000000000159931436 transport-4912 DEBUG Timeout rescheduled for session 0x1f445e8 set to 300000
июн 21 13:29:08-00000000000159932126 transport-udp-4912 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:29:08-00000000000159932126 transport-udp-4912 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:29:08-00000000000159932126 transport-udp-4912 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297'
июн 21 13:29:08-00000000000159932126 transport-udp-4912 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:29:08-00000000000159932126 transport-udp-4912 DEBUG Found existing session 0x1f445e8
июн 21 13:29:08-00000000000159932126 transport-4912 DEBUG Timeout rescheduled for session 0x1f445e8 set to 300000
июн 21 13:29:08-00000000000159932127 transport-udp-4912 DEBUG UDP session 0x1f3f358 for peer `JP32' is not in the map
июн 21 13:29:08-00000000000159932127 transport-4912 ERROR Assertion failed at plugin_transport_udp.c:1146.
TagsNo tags attached.

Activities

LRN

2012-06-21 11:53

developer   ~0006120

Made it crash, attached a debugger. Here's a backtrace:
Program received signal SIGTRAP, Trace/breakpoint trap.
0x7677280d in KERNELBASE!DeleteAce () from C:\Windows\syswow64\KernelBase.dll
(gdb) bt
#0  0x7677280d in KERNELBASE!DeleteAce () from C:\Windows\syswow64\KernelBase.dll
#1  0x62ac6628 in GNUNET_abort () at common_logging.c:271
#2  0x6eac3c24 in _fu110__skip_log () at plugin_transport_udp.c:1147
#3  0x0040bd7c in _fu446__skip_log () at gnunet-service-transport_neighbours.c:1581
#4  0x0040ca7c in _fu485__skip_log () at gnunet-service-transport_neighbours.c:1823
#5  0x00404e76 in _fu155__skip_log () at gnunet-service-transport_blacklist.c:758
#6  0x0040d465 in _fu506__skip_log () at gnunet-service-transport_neighbours.c:1984
#7  0x0040e518 in _fu554__skip_log () at gnunet-service-transport_neighbours.c:2212
#8  0x00402291 in _fu35__skip_log () at gnunet-service-transport.c:439
#9  0x654c2d7d in _fu86__skip_log () at ats_api_scheduling.c:626
#10 0x62ac3b19 in receive_task (cls=0x71e888, tc=0x28fc80) at client.c:584
#11 0x62af5f4a in run_ready (rs=0x621b08, ws=0x719fe8) at scheduler.c:602
#12 0x62af66bb in GNUNET_SCHEDULER_run (task=0x62b02200 <service_task>, task_cls=0x28fe20) at scheduler.c:790
#13 0x62b02eeb in GNUNET_SERVICE_run (argc=3, argv=0x61c5c8, service_name=0x4183ab "transport", options=GNUNET_SERVICE_OPTION_NONE, task=0x4025e7 <run>, task_cls=0x0) at service.c:1785
#14 0x00402ba3 in main (argc=3, argv=0x61c5c8) at gnunet-service-transport.c:648
(gdb) up
#1  0x62ac6628 in GNUNET_abort () at common_logging.c:271
271       DebugBreak ();
(gdb)
#2  0x6eac3c24 in _fu110__skip_log () at plugin_transport_udp.c:1147
1147        GNUNET_abort ();
(gdb)
#3  0x0040bd7c in _fu446__skip_log () at gnunet-service-transport_neighbours.c:1581
1581      (void) papi->send (papi->cls,
(gdb) l
1576      }
1577      connect_msg.header.size = htons (sizeof (struct SessionConnectMessage));
1578      connect_msg.header.type = htons (GNUNET_MESSAGE_TYPE_TRANSPORT_SESSION_CONNECT_ACK);
1579      connect_msg.reserved = htonl (0);
1580      connect_msg.timestamp = GNUNET_TIME_absolute_hton (timestamp);
1581      (void) papi->send (papi->cls,
1582                         session,
1583                         (const char *) &connect_msg, sizeof (struct SessionConnectMessage),
1584                         UINT_MAX,
1585                         GNUNET_TIME_UNIT_FOREVER_REL,
(gdb) up
#4  0x0040ca7c in _fu485__skip_log () at gnunet-service-transport_neighbours.c:1823
1823          send_session_connect_ack_message (bcc->na.address,
(gdb) l
1818          break; /* result for an address we currently don't care about */
1819        if (GNUNET_OK == result)
1820        {
1821          n->timeout = GNUNET_TIME_relative_to_absolute (SETUP_CONNECTION_TIMEOUT);
1822          n->state = S_CONNECT_RECV_ACK;
1823          send_session_connect_ack_message (bcc->na.address,
1824                                            bcc->na.session,
1825                                            n->connect_ack_timestamp);
1826          if (1 == n->send_connect_ack)
1827            n->send_connect_ack = 2;
(gdb) p bcc->na.session
$1 = (struct Session *) 0x63bbc0
(gdb) p *bcc->na.session
$2 = {target = {hashPubKey = {bits = {6560496, 6540272, 1048913391, 2972894207, 2569129885, 2695688379, 4190893878, 2453216288, 971494754, 3314863728, 2112834472, 483238290, 7002803, 390580153, 15549539, 1584227496}}},
  frag_ctx = 0x0, sock_addr = 0x63bc40, flow_delay_for_other_peer = {rel_value = 0}, flow_delay_from_other_peer = {abs_value = 0}, timeout_task = 0, last_expected_delay = {rel_value = 1000}, ats = {type = 50331648,
    value = 33554432}, addrlen = 16, rc = 0, in_destroy = 0}
(gdb)

And the logfile contents:
июн 21 13:47:55-00000000000161059344 transport-udp-11000 DEBUG Setting up sockets
июн 21 13:47:55-00000000000161059344 transport-udp-11000 DEBUG Binding to IPv4 port 12272
июн 21 13:47:55-00000000000161059344 transport-udp-11000 DEBUG Starting broadcasting
июн 21 13:47:55-00000000000161059358 transport-udp-11000 DEBUG UDP received 340(340)-byte message from `127.0.0.1:12272' type 384
июн 21 13:47:55-00000000000161059359 transport-udp-11000 DEBUG UDP received 340(340)-byte message from `169.254.92.128:12272' type 384
июн 21 13:47:55-00000000000161059359 transport-udp-11000 DEBUG UDP received 340(340)-byte message from `192.168.4.39:12272' type 384
июн 21 13:47:57-00000000000161060877 transport-udp-11000 DEBUG UDP received 506(506)-byte message from `169.254.92.128:12247' type 56
июн 21 13:47:57-00000000000161060877 transport-udp-11000 DEBUG Received message with 506 bytes from peer `B3CP' at `169.254.92.128:12247'
июн 21 13:47:57-00000000000161060878 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:57-00000000000161060878 transport-11000 DEBUG Timeout for session 0x63bbc0 set to 300000
июн 21 13:47:57-00000000000161060878 transport-udp-11000 DEBUG Creating new session 0x63bbc0 for peer `B3CP' address `169.254.92.128:12247'
июн 21 13:47:57-00000000000161060878 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:57-00000000000161060893 transport-udp-11000 DEBUG UDP transmits 366-byte message to `B3CP' using address `169.254.92.128:12247'
июн 21 13:47:57-00000000000161060893 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:57-00000000000161060893 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:57-00000000000161060909 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:57-00000000000161060909 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12247 <-> 169.254.92.128:12247
июн 21 13:47:57-00000000000161060909 transport-udp-11000 DEBUG Found existing session 0x63bbc0
июн 21 13:47:57-00000000000161060909 transport-udp-11000 DEBUG UDP transmits 506-byte message to `B3CP' using address `169.254.92.128:12247'
июн 21 13:47:57-00000000000161060909 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:57-00000000000161060911 transport-udp-11000 DEBUG UDP received 506(506)-byte message from `169.254.92.128:12372' type 56
июн 21 13:47:57-00000000000161060911 transport-udp-11000 DEBUG Received message with 506 bytes from peer `UOOE' at `169.254.92.128:12372'
июн 21 13:47:57-00000000000161060911 transport-udp-11000 DEBUG Looking for existing session for peer `UOOE' `169.254.92.128:12372' 
июн 21 13:47:57-00000000000161060911 transport-11000 DEBUG Timeout for session 0x62a150 set to 300000
июн 21 13:47:57-00000000000161060911 transport-udp-11000 DEBUG Creating new session 0x62a150 for peer `UOOE' address `169.254.92.128:12372'
июн 21 13:47:57-00000000000161060912 transport-11000 DEBUG Timeout rescheduled for session 0x62a150 set to 300000
июн 21 13:47:57-00000000000161060912 transport-udp-11000 DEBUG UDP transmits 366-byte message to `UOOE' using address `169.254.92.128:12372'
июн 21 13:47:57-00000000000161060912 transport-11000 DEBUG Timeout rescheduled for session 0x62a150 set to 300000
июн 21 13:47:57-00000000000161060912 transport-11000 DEBUG Timeout rescheduled for session 0x62a150 set to 300000
июн 21 13:47:57-00000000000161060912 transport-udp-11000 DEBUG Message for peer `UOOE' (366 bytes) is not delayed 
июн 21 13:47:57-00000000000161060912 transport-udp-11000 DEBUG UDP transmitted 366-byte message to `169.254.92.128:12372' (366: ok)
июн 21 13:47:57-00000000000161060912 transport-udp-11000 DEBUG Calling continuation for 366 byte message to `UOOE' with result OK
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG Looking for existing session for peer `UOOE' `169.254.92.128:12372' 
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12372 <-> 169.254.92.128:12372
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG Found existing session 0x62a150
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG UDP transmits 506-byte message to `UOOE' using address `169.254.92.128:12372'
июн 21 13:47:57-00000000000161060916 transport-11000 DEBUG Timeout rescheduled for session 0x62a150 set to 300000
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:57-00000000000161060916 transport-11000 DEBUG Timeout for session 0x642000 set to 300000
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG Creating new session 0x642000 for peer `GHT1' address `169.254.92.128:12172'
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG UDP transmits 506-byte message to `GHT1' using address `169.254.92.128:12172'
июн 21 13:47:57-00000000000161060916 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:57-00000000000161060916 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:57-00000000000161060917 transport-11000 DEBUG Timeout for session 0x642748 set to 300000
июн 21 13:47:57-00000000000161060917 transport-udp-11000 DEBUG Creating new session 0x642748 for peer `JP32' address `169.254.92.128:12297'
июн 21 13:47:57-00000000000161060917 transport-udp-11000 DEBUG UDP transmits 506-byte message to `JP32' using address `169.254.92.128:12297'
июн 21 13:47:57-00000000000161060917 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:57-00000000000161060917 transport-udp-11000 DEBUG Message for peer `JP32' (506 bytes) is not delayed 
июн 21 13:47:57-00000000000161060917 transport-udp-11000 DEBUG UDP transmitted 506-byte message to `169.254.92.128:12297' (506: ok)
июн 21 13:47:57-00000000000161060917 transport-udp-11000 DEBUG Calling continuation for 506 byte message to `JP32' with result OK
июн 21 13:47:57-00000000000161060918 transport-udp-11000 DEBUG Message for peer `GHT1' (506 bytes) is not delayed 
июн 21 13:47:57-00000000000161060918 transport-udp-11000 DEBUG UDP transmitted 506-byte message to `169.254.92.128:12172' (506: ok)
июн 21 13:47:57-00000000000161060918 transport-udp-11000 DEBUG Calling continuation for 506 byte message to `GHT1' with result OK
июн 21 13:47:57-00000000000161060919 transport-udp-11000 DEBUG Message for peer `UOOE' (506 bytes) is not delayed 
июн 21 13:47:57-00000000000161060919 transport-udp-11000 DEBUG UDP transmitted 506-byte message to `169.254.92.128:12372' (506: ok)
июн 21 13:47:57-00000000000161060919 transport-udp-11000 DEBUG Calling continuation for 506 byte message to `UOOE' with result OK
июн 21 13:47:57-00000000000161060921 transport-udp-11000 DEBUG Message for peer `B3CP' (506 bytes) is not delayed 
июн 21 13:47:57-00000000000161060921 transport-udp-11000 DEBUG UDP transmitted 506-byte message to `169.254.92.128:12247' (506: ok)
июн 21 13:47:57-00000000000161060921 transport-udp-11000 DEBUG Calling continuation for 506 byte message to `B3CP' with result OK
июн 21 13:47:57-00000000000161060923 transport-udp-11000 DEBUG Message for peer `B3CP' (366 bytes) is not delayed 
июн 21 13:47:57-00000000000161060923 transport-udp-11000 DEBUG UDP transmitted 366-byte message to `169.254.92.128:12247' (366: ok)
июн 21 13:47:57-00000000000161060924 transport-udp-11000 DEBUG Calling continuation for 366 byte message to `B3CP' with result OK
июн 21 13:47:57-00000000000161060933 transport-udp-11000 DEBUG UDP received 506(506)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:57-00000000000161060933 transport-udp-11000 DEBUG Received message with 506 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:57-00000000000161060933 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:57-00000000000161060933 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:57-00000000000161060933 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:57-00000000000161060937 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:57-00000000000161060937 transport-udp-11000 DEBUG UDP transmits 366-byte message to `JP32' using address `169.254.92.128:12297'
июн 21 13:47:57-00000000000161060937 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:57-00000000000161060937 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:57-00000000000161060937 transport-udp-11000 DEBUG Message for peer `JP32' (366 bytes) is not delayed 
июн 21 13:47:57-00000000000161060937 transport-udp-11000 DEBUG UDP transmitted 366-byte message to `169.254.92.128:12297' (366: ok)
июн 21 13:47:57-00000000000161060937 transport-udp-11000 DEBUG Calling continuation for 366 byte message to `JP32' with result OK
июн 21 13:47:57-00000000000161060943 transport-udp-11000 DEBUG UDP received 366(366)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:57-00000000000161060943 transport-udp-11000 DEBUG Received message with 366 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:57-00000000000161060943 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:57-00000000000161060943 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:57-00000000000161060943 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:57-00000000000161060951 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:57-00000000000161060956 transport-udp-11000 DEBUG UDP received 506(506)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:57-00000000000161060956 transport-udp-11000 DEBUG Received message with 506 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:57-00000000000161060956 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:57-00000000000161060956 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:57-00000000000161060956 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:57-00000000000161060957 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:57-00000000000161060957 transport-udp-11000 DEBUG UDP transmits 366-byte message to `GHT1' using address `169.254.92.128:12172'
июн 21 13:47:57-00000000000161060957 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:57-00000000000161060957 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:57-00000000000161060957 transport-udp-11000 DEBUG UDP received 366(366)-byte message from `169.254.92.128:12372' type 56
июн 21 13:47:57-00000000000161060957 transport-udp-11000 DEBUG Received message with 366 bytes from peer `UOOE' at `169.254.92.128:12372'
июн 21 13:47:57-00000000000161060957 transport-udp-11000 DEBUG Looking for existing session for peer `UOOE' `169.254.92.128:12372' 
июн 21 13:47:57-00000000000161060957 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12372 <-> 169.254.92.128:12372
июн 21 13:47:57-00000000000161060957 transport-udp-11000 DEBUG Found existing session 0x62a150
июн 21 13:47:57-00000000000161060958 transport-11000 DEBUG Timeout rescheduled for session 0x62a150 set to 300000
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG Message for peer `GHT1' (366 bytes) is not delayed 
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG UDP transmitted 366-byte message to `169.254.92.128:12172' (366: ok)
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG Calling continuation for 366 byte message to `GHT1' with result OK
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG UDP received 366(366)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG Received message with 366 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:57-00000000000161060958 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:57-00000000000161060961 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:57-00000000000161060968 transport-udp-11000 DEBUG UDP received 366(366)-byte message from `169.254.92.128:12247' type 56
июн 21 13:47:57-00000000000161060968 transport-udp-11000 DEBUG Received message with 366 bytes from peer `B3CP' at `169.254.92.128:12247'
июн 21 13:47:57-00000000000161060968 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:57-00000000000161060968 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12247 <-> 169.254.92.128:12247
июн 21 13:47:57-00000000000161060968 transport-udp-11000 DEBUG Found existing session 0x63bbc0
июн 21 13:47:57-00000000000161060972 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:58-00000000000161061890 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12247' type 56
июн 21 13:47:58-00000000000161061890 transport-udp-11000 DEBUG Received message with 88 bytes from peer `B3CP' at `169.254.92.128:12247'
июн 21 13:47:58-00000000000161061890 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:58-00000000000161061890 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12247 <-> 169.254.92.128:12247
июн 21 13:47:58-00000000000161061890 transport-udp-11000 DEBUG Found existing session 0x63bbc0
июн 21 13:47:58-00000000000161061890 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:58-00000000000161061892 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12247' type 56
июн 21 13:47:58-00000000000161061892 transport-udp-11000 DEBUG Received message with 88 bytes from peer `B3CP' at `169.254.92.128:12247'
июн 21 13:47:58-00000000000161061892 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:58-00000000000161061892 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12247 <-> 169.254.92.128:12247
июн 21 13:47:58-00000000000161061892 transport-udp-11000 DEBUG Found existing session 0x63bbc0
июн 21 13:47:58-00000000000161061892 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:58-00000000000161061894 transport-udp-11000 DEBUG UDP transmits 88-byte message to `B3CP' using address `169.254.92.128:12247'
июн 21 13:47:58-00000000000161061894 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:58-00000000000161061894 transport-udp-11000 DEBUG Message for peer `B3CP' (88 bytes) is not delayed 
июн 21 13:47:58-00000000000161061894 transport-udp-11000 DEBUG UDP transmitted 88-byte message to `169.254.92.128:12247' (88: ok)
июн 21 13:47:58-00000000000161061895 transport-udp-11000 DEBUG Calling continuation for 88 byte message to `B3CP' with result OK
июн 21 13:47:58-00000000000161061907 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061907 transport-udp-11000 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061907 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061907 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061907 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061907 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061911 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061912 transport-udp-11000 DEBUG Received message with 76 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061912 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061912 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061912 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061912 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061914 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061914 transport-udp-11000 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061914 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061914 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061914 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061914 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061916 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061916 transport-udp-11000 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061916 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061916 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061916 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061916 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061917 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061917 transport-udp-11000 DEBUG Received message with 88 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061917 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061917 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061917 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061917 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061920 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161061920 transport-udp-11000 DEBUG Received message with 88 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161061920 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161061920 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161061920 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161061920 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161061921 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161061921 transport-udp-11000 DEBUG Received message with 88 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161061921 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161061921 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161061921 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161061921 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161061923 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161061923 transport-udp-11000 DEBUG Received message with 76 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161061923 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161061923 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161061923 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161061923 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161061925 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061925 transport-udp-11000 DEBUG Received message with 76 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061925 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061925 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061925 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061926 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061994 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061994 transport-udp-11000 DEBUG Received message with 76 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061994 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061994 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061994 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061994 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161061995 transport-udp-11000 DEBUG UDP received 672(672)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161061995 transport-udp-11000 DEBUG Received message with 672 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161061995 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161061995 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161061995 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161061995 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062034 transport-udp-11000 DEBUG UDP received 148(148)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161062034 transport-udp-11000 DEBUG Received message with 148 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161062034 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161062034 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161062034 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161062034 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062107 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161062107 transport-udp-11000 DEBUG Received message with 76 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161062107 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161062107 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161062107 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161062107 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062131 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161062131 transport-udp-11000 DEBUG Received message with 76 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161062131 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161062131 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161062131 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161062131 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161062135 transport-udp-11000 DEBUG UDP received 672(672)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161062135 transport-udp-11000 DEBUG Received message with 672 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161062135 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161062135 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161062135 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161062135 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161062136 transport-udp-11000 DEBUG UDP received 148(148)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161062136 transport-udp-11000 DEBUG Received message with 148 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161062137 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG UDP received 76(76)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Received message with 76 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161062137 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161062137 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161062148 transport-udp-11000 DEBUG UDP received 152(152)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161062148 transport-udp-11000 DEBUG Received message with 152 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161062148 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161062148 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161062148 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161062148 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062169 transport-udp-11000 DEBUG UDP received 152(152)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161062169 transport-udp-11000 DEBUG Received message with 152 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161062169 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161062169 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161062169 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161062169 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161062171 transport-udp-11000 DEBUG UDP received 210(210)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161062171 transport-udp-11000 DEBUG Received message with 210 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161062171 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161062171 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161062171 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161062171 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062176 transport-udp-11000 DEBUG UDP received 210(210)-byte message from `169.254.92.128:12172' type 56
июн 21 13:47:58-00000000000161062176 transport-udp-11000 DEBUG Received message with 210 bytes from peer `GHT1' at `169.254.92.128:12172'
июн 21 13:47:58-00000000000161062176 transport-udp-11000 DEBUG Looking for existing session for peer `GHT1' `169.254.92.128:12172' 
июн 21 13:47:58-00000000000161062176 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12172 <-> 169.254.92.128:12172
июн 21 13:47:58-00000000000161062176 transport-udp-11000 DEBUG Found existing session 0x642000
июн 21 13:47:58-00000000000161062176 transport-11000 DEBUG Timeout rescheduled for session 0x642000 set to 300000
июн 21 13:47:58-00000000000161062202 transport-udp-11000 DEBUG UDP received 716(716)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161062202 transport-udp-11000 DEBUG Received message with 716 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161062202 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161062202 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161062202 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161062202 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062212 transport-udp-11000 DEBUG UDP received 716(716)-byte message from `169.254.92.128:12297' type 56
июн 21 13:47:58-00000000000161062212 transport-udp-11000 DEBUG Received message with 716 bytes from peer `JP32' at `169.254.92.128:12297'
июн 21 13:47:58-00000000000161062212 transport-udp-11000 DEBUG Looking for existing session for peer `JP32' `169.254.92.128:12297' 
июн 21 13:47:58-00000000000161062212 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12297 <-> 169.254.92.128:12297
июн 21 13:47:58-00000000000161062213 transport-udp-11000 DEBUG Found existing session 0x642748
июн 21 13:47:58-00000000000161062213 transport-11000 DEBUG Timeout rescheduled for session 0x642748 set to 300000
июн 21 13:47:58-00000000000161062425 transport-udp-11000 DEBUG UDP transmits 616-byte message to `B3CP' using address `169.254.92.128:12247'
июн 21 13:47:58-00000000000161062425 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 set to 300000
июн 21 13:47:58-00000000000161062426 transport-udp-11000 DEBUG Message for peer `B3CP' (616 bytes) is not delayed 
июн 21 13:47:58-00000000000161062426 transport-udp-11000 DEBUG UDP transmitted 616-byte message to `169.254.92.128:12247' (616: ok)
июн 21 13:47:58-00000000000161062426 transport-udp-11000 DEBUG Calling continuation for 616 byte message to `B3CP' with result OK
июн 21 13:47:58-00000000000161062429 transport-udp-11000 DEBUG Disconnecting from peer `B3CP'
июн 21 13:47:58-00000000000161062429 transport-udp-11000 DEBUG Session 0x63bbc0 to peer `B3CP' address ended 
июн 21 13:47:58-00000000000161062429 transport-11000 DEBUG Timeout rescheduled for session 0x63bbc0 canceled
июн 21 13:47:58-00000000000161062441 transport-udp-11000 DEBUG UDP received 616(616)-byte message from `169.254.92.128:12247' type 56
июн 21 13:47:58-00000000000161062441 transport-udp-11000 DEBUG Received message with 616 bytes from peer `B3CP' at `169.254.92.128:12247'
июн 21 13:47:58-00000000000161062441 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:58-00000000000161062441 transport-11000 DEBUG Timeout for session 0x63c718 set to 300000
июн 21 13:47:58-00000000000161062441 transport-udp-11000 DEBUG Creating new session 0x63c718 for peer `B3CP' address `169.254.92.128:12247'
июн 21 13:47:58-00000000000161062441 transport-11000 DEBUG Timeout rescheduled for session 0x63c718 set to 300000
июн 21 13:47:59-00000000000161063368 transport-udp-11000 DEBUG UDP received 88(88)-byte message from `169.254.92.128:12247' type 56
июн 21 13:47:59-00000000000161063368 transport-udp-11000 DEBUG Received message with 88 bytes from peer `B3CP' at `169.254.92.128:12247'
июн 21 13:47:59-00000000000161063368 transport-udp-11000 DEBUG Looking for existing session for peer `B3CP' `169.254.92.128:12247' 
июн 21 13:47:59-00000000000161063368 transport-udp-11000 DEBUG Comparing  address 169.254.92.128:12247 <-> 169.254.92.128:12247
июн 21 13:47:59-00000000000161063368 transport-udp-11000 DEBUG Found existing session 0x63c718
июн 21 13:47:59-00000000000161063368 transport-11000 DEBUG Timeout rescheduled for session 0x63c718 set to 300000
июн 21 13:47:59-00000000000161063369 transport-udp-11000 DEBUG UDP session 0x63bbc0 for peer `U0D6' is not in the map
июн 21 13:47:59-00000000000161063369 transport-11000 ERROR Assertion failed at plugin_transport_udp.c:1146.

LRN

2012-06-21 16:44

developer   ~0006126

Also note that peer IDs do not match in the log. Here's a trimmed example:
util-scheduler-6192 DEBUG Running task: 789 / 0x1d91780
util-6192 DEBUG Received message of type 345 and size 114
transport-6192 DEBUG process_ats_message 0x28fb70
ats-scheduling-api-6192 DEBUG Find session 1 from peer 2TTQ in 0x2d248
transport-6192 DEBUG ATS tells us to switch to address '169.254.92.128:12222' session 0x1da3578 for peer `2TTQ' in state S_CONNECT_RECV_ATS
transport-6192 DEBUG Connection to new address of peer `2TTQ' based on blacklist is `allowed'
transport-udp-6192 DEBUG UDP session 0x1da3578 for peer `DGRI' is not in the map
transport-6192 ERROR Assertion failed at plugin_transport_udp.c:1146.

Note that find_session() in ATS client is called with 2TTQ peer id, but in udp lookup is made for peer DGRI, because it uses id from the session object. ATS client, on the other hand, uses separate peer ID field in SessionRecord for checks, and it might be different from the ID in session object.

Christian Grothoff

2012-06-22 19:15

manager   ~0006134

Subject: [PATCH] Mark session as completely disconnected later.

  free_neighbour() calls plugin's disconnect() routine, which will invoke
environment session free callback, which will do NOTHING if session is
in "completely disconnected" state (in just "disconnected" state it
will free primary address).

Destroy address in free_address() to make ATS forget the session.

Fixes 0002446 (SVN 22213).

Issue History

Date Modified Username Field Change
2012-06-21 11:42 LRN New Issue
2012-06-21 11:42 LRN Status new => assigned
2012-06-21 11:42 LRN Assigned To => Matthias Wachs
2012-06-21 11:53 LRN Note Added: 0006120
2012-06-21 16:44 LRN Note Added: 0006126
2012-06-22 11:00 Christian Grothoff Target Version => 0.9.4
2012-06-22 19:15 Christian Grothoff Assigned To Matthias Wachs => LRN
2012-06-22 19:15 Christian Grothoff Note Added: 0006134
2012-06-22 19:15 Christian Grothoff Status assigned => resolved
2012-06-22 19:15 Christian Grothoff Fixed in Version => 0.9.4
2012-06-22 19:15 Christian Grothoff Resolution open => fixed
2012-11-05 18:34 Christian Grothoff Status resolved => closed
2024-05-03 13:58 Christian Grothoff Category UDP transport => transport service