Output details of encryption errors #3

MSch · 2012-09-30T00:12:05Z

No description provided.

gsliepen · 2012-09-30T11:07:40Z

Merged.

(gdb) bt #0 mst_kruskal () at graph.c:107 #1 graph () at graph.c:302 #2 0x00007ffff7b509fe in del_edge_h (c=<optimized out>, request=<optimized out>) at protocol_edge.c:292 #3 0x00007ffff7b4de2e in receive_request (c=0x5555557e3ef0, request=0x555555800e13 "13 3fc17404 node1 node2") at protocol.c:136 #4 0x00007ffff7b43513 in receive_meta (c=0x5555557e3ef0) at meta.c:290 #5 0x00007ffff7b442d9 in handle_meta_connection_data (c=0x5555557e3ef0) at net.c:291 gsliepen#6 0x00007ffff7b41391 in event_loop () at event.c:287 gsliepen#7 0x00007ffff7b449b2 in main_loop () at net.c:469 gsliepen#8 0x0000555555556716 in main (argc=<optimized out>, argv=<optimized out>) at tincd.c:480

I have observed cases where this code can get stuck on the GetOverlappedResult(), especially when the computer is waking up from sleep. This is problematic when combined with DeviceStandby=yes: other_side (1.2.3.4 port 655) didn't respond to PING in 5 seconds Closing connection with other_side (1.2.3.4 port 655) Disabling Windows tap device <STUCK> gdb reveals the following stack trace: #0 0x77c7dd3c in ?? () gsliepen#1 0x7482aad0 in KERNELBASE!GetOverlappedResult () from C:\WINDOWS\SysWoW64\KernelBase.dll gsliepen#2 0x0043c343 in disable_device () at mingw/device.c:244 gsliepen#3 0x0040fcee in device_disable () at net_setup.c:759 gsliepen#4 0x00405bb5 in check_reachability () at graph.c:292 gsliepen#5 0x00405be2 in graph () at graph.c:301 gsliepen#6 0x004088db in terminate_connection (c=0x4dea5c0, report=true) at net.c:108 gsliepen#7 0x00408aed in timeout_handler (data=0x5af0c0 <pingtimer>) at net.c:168 gsliepen#8 0x00403af8 in get_time_remaining (diff=0x2a8fd64) at event.c:239 gsliepen#9 0x00403b6c in event_loop () at event.c:303 gsliepen#10 0x00409904 in main_loop () at net.c:461 gsliepen#11 0x00424a95 in main2 (argc=6, argv=0x2b42a60) at tincd.c:489 gsliepen#12 0x00424788 in main (argc=6, argv=0x2b42a60) at tincd.c:416 This is with TAP-Win32 9.0.0.9. I suspect driver bugs related to sleep. In any case, this commit fixes the issue by cancelling I/O only when the entire tinc process is being gracefully shut down, as opposed to every time the device is disabled. Thankfully, the driver seems to be perfectly fine with this code issuing TAP_IOCTL_SET_MEDIA_STATUS ioctls while there are I/O operations inflight.

I have observed cases where disable_device() can get stuck on the GetOverlappedResult() call, especially when the computer is waking up from sleep. This is problematic when combined with DeviceStandby=yes: other_side (1.2.3.4 port 655) didn't respond to PING in 5 seconds Closing connection with other_side (1.2.3.4 port 655) Disabling Windows tap device <STUCK> gdb reveals the following stack trace: #0 0x77c7dd3c in ?? () gsliepen#1 0x7482aad0 in KERNELBASE!GetOverlappedResult () from C:\WINDOWS\SysWoW64\KernelBase.dll gsliepen#2 0x0043c343 in disable_device () at mingw/device.c:244 gsliepen#3 0x0040fcee in device_disable () at net_setup.c:759 gsliepen#4 0x00405bb5 in check_reachability () at graph.c:292 gsliepen#5 0x00405be2 in graph () at graph.c:301 gsliepen#6 0x004088db in terminate_connection (c=0x4dea5c0, report=true) at net.c:108 gsliepen#7 0x00408aed in timeout_handler (data=0x5af0c0 <pingtimer>) at net.c:168 gsliepen#8 0x00403af8 in get_time_remaining (diff=0x2a8fd64) at event.c:239 gsliepen#9 0x00403b6c in event_loop () at event.c:303 gsliepen#10 0x00409904 in main_loop () at net.c:461 gsliepen#11 0x00424a95 in main2 (argc=6, argv=0x2b42a60) at tincd.c:489 gsliepen#12 0x00424788 in main (argc=6, argv=0x2b42a60) at tincd.c:416 This is with TAP-Win32 9.0.0.9. I suspect driver bugs related to sleep. In any case, this commit fixes the issue by cancelling I/O only when the entire tinc process is being gracefully shut down, as opposed to every time the device is disabled. Thankfully, the driver seems to be perfectly fine with this code issuing TAP_IOCTL_SET_MEDIA_STATUS ioctls while there are I/O operations inflight.

Steps to reproduce: 0. build tincd with -fsanitize=address 1. start tincd: ../../src/tincd -c . -D 2. capture log output in one tinc client ../../src/tinc -c . log 3. this is optional, but seems to flush the bug more often: open another tinc client and issue the purge/retry commands: ../../src/tinc -c . tinc> purge tinc> retry 4. stop tincd (using Ctrl+C or the stop command) Repeat until it fails with a bunch of error messages as below. ------------ ==1715850==ERROR: AddressSanitizer: heap-use-after-free on address 0x60300001d950 at pc 0x55a3fdba1fa5 bp 0x7fffbd250470 sp 0x7fffbd250468 READ of size 8 at 0x60300001d950 thread T0 #0 0x55a3fdba1fa4 in real_logger tinc/src/logger.c:101:7 gsliepen#1 0x55a3fdba188b in logger tinc/src/logger.c:140:2 gsliepen#2 0x55a3fdc90c22 in main tinc/src/tincd.c:625:2 gsliepen#3 0x7f826a3eab24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24) gsliepen#4 0x55a3fda9087d in _start (tinc/src/tincd+0xd487d) 0x60300001d950 is located 0 bytes inside of 32-byte region [0x60300001d950,0x60300001d970) freed by thread T0 here: #0 0x55a3fdb377c9 in free (tinc/src/tincd+0x17b7c9) gsliepen#1 0x55a3fdb9e1b4 in list_free tinc/src/list.c:36:2 gsliepen#2 0x55a3fdba0ed3 in list_delete_list tinc/src/list.c:192:2 gsliepen#3 0x55a3fdb8385f in exit_connections tinc/src/connection.c:47:2 gsliepen#4 0x55a3fdbf0427 in close_network_connections tinc/src/net_setup.c:1386:2 gsliepen#5 0x55a3fdc90c0d in main tinc/src/tincd.c:623:2 gsliepen#6 0x7f826a3eab24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24) previously allocated by thread T0 here: #0 0x55a3fdb37c91 in calloc (tinc/src/tincd+0x17bc91) gsliepen#1 0x55a3fdb9e157 in xzalloc tinc/src/./xalloc.h:37:12 gsliepen#2 0x55a3fdb9e065 in list_alloc tinc/src/list.c:29:17 gsliepen#3 0x55a3fdb82a43 in init_connections tinc/src/connection.c:40:20 gsliepen#4 0x55a3fdbea58c in setup_network tinc/src/net_setup.c:1304:2 gsliepen#5 0x55a3fdc90535 in main tinc/src/tincd.c:573:6 gsliepen#6 0x7f826a3eab24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24)

Steps to reproduce: 0. build tincd with -fsanitize=address 1. start tincd: ./src/tincd -c . -D 2. capture log output in one tinc client ./src/tinc -c . log 3. this is optional, but seems to flush the bug more often: open another tinc client and issue the purge/retry commands: ./src/tinc -c . tinc> purge tinc> retry 4. stop tincd (using Ctrl+C or the stop command) Repeat until it fails with a bunch of error messages as below. ------------ ==1715850==ERROR: AddressSanitizer: heap-use-after-free on address 0x60300001d950 at pc 0x55a3fdba1fa5 bp 0x7fffbd250470 sp 0x7fffbd250468 READ of size 8 at 0x60300001d950 thread T0 #0 0x55a3fdba1fa4 in real_logger tinc/src/logger.c:101:7 gsliepen#1 0x55a3fdba188b in logger tinc/src/logger.c:140:2 gsliepen#2 0x55a3fdc90c22 in main tinc/src/tincd.c:625:2 gsliepen#3 0x7f826a3eab24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24) gsliepen#4 0x55a3fda9087d in _start (tinc/src/tincd+0xd487d) 0x60300001d950 is located 0 bytes inside of 32-byte region [0x60300001d950,0x60300001d970) freed by thread T0 here: #0 0x55a3fdb377c9 in free (tinc/src/tincd+0x17b7c9) gsliepen#1 0x55a3fdb9e1b4 in list_free tinc/src/list.c:36:2 gsliepen#2 0x55a3fdba0ed3 in list_delete_list tinc/src/list.c:192:2 gsliepen#3 0x55a3fdb8385f in exit_connections tinc/src/connection.c:47:2 gsliepen#4 0x55a3fdbf0427 in close_network_connections tinc/src/net_setup.c:1386:2 gsliepen#5 0x55a3fdc90c0d in main tinc/src/tincd.c:623:2 gsliepen#6 0x7f826a3eab24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24) previously allocated by thread T0 here: #0 0x55a3fdb37c91 in calloc (tinc/src/tincd+0x17bc91) gsliepen#1 0x55a3fdb9e157 in xzalloc tinc/src/./xalloc.h:37:12 gsliepen#2 0x55a3fdb9e065 in list_alloc tinc/src/list.c:29:17 gsliepen#3 0x55a3fdb82a43 in init_connections tinc/src/connection.c:40:20 gsliepen#4 0x55a3fdbea58c in setup_network tinc/src/net_setup.c:1304:2 gsliepen#5 0x55a3fdc90535 in main tinc/src/tincd.c:573:6 gsliepen#6 0x7f826a3eab24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24)

The whitespace trimming code was going before the start of the line read from the host config file. ==1917089==ERROR: AddressSanitizer: stack-buffer-underflow on address 0x7ffee3a90f9f at pc 0x55a6b10989b9 bp 0x7ffee3a90e50 sp 0x7ffee3a90e48 READ of size 1 at 0x7ffee3a90f9f thread T0 #0 0x55a6b10989b8 in check_conffile tinc/src/fsck.c:131:27 gsliepen#1 0x55a6b10974b3 in fsck_check_config_variables tinc/src/fsck.c:728:4 gsliepen#2 0x55a6b1096b0c in fsck_check_scripts_and_configs tinc/src/fsck.c:749:2 gsliepen#3 0x55a6b109311a in fsck tinc/src/fsck.c:767:6 gsliepen#4 0x55a6b10e7b81 in cmd_fsck tinc/src/tincctl.c:2817:9 gsliepen#5 0x55a6b10d70af in main tinc/src/tincctl.c:3436:11 gsliepen#6 0x7fc36e12cb24 in __libc_start_main (/usr/lib/libc.so.6+0x27b24) gsliepen#7 0x55a6b0fb48bd in _start (tinc/src/tinc+0x6c8bd) Address 0x7ffee3a90f9f is located in stack of thread T0 at offset 31 in frame #0 0x55a6b10983bf in check_conffile tinc/src/fsck.c:92

linux/device.c:149:11: runtime error: implicit conversion from type 'ssize_t' (aka 'long') of value -1 (64-bit, signed) to type 'size_t' (aka 'unsigned long') changed the value to 18446744073709551615 (64-bit, unsigned) #0 0x55e3cb851f84 in read_packet /home/runner/work/tinc/tinc/src/linux/device.c:149:11 gsliepen#1 0x55e3cb7bb7fe in handle_device_data /home/runner/work/tinc/tinc/src/net_packet.c:1906:5 gsliepen#2 0x55e3cb78e6e0 in event_loop /home/runner/work/tinc/tinc/src/event.c:353:5 gsliepen#3 0x55e3cb7a6a90 in main_loop /home/runner/work/tinc/tinc/src/net.c:505:6 gsliepen#4 0x55e3cb83d241 in main /home/runner/work/tinc/tinc/src/tincd.c:614:11 gsliepen#5 0x7fec881950b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2) gsliepen#6 0x55e3cb757dcd in _start (/home/runner/work/tinc/tinc/src/tincd+0x9adcd) SUMMARY: UndefinedBehaviorSanitizer: undefined-behavior linux/device.c:149:11 in linux/device.c:163:23: runtime error: unsigned integer overflow: 18446744073709551615 + 10 cannot be represented in type 'unsigned long' #0 0x55e3cb852253 in read_packet /home/runner/work/tinc/tinc/src/linux/device.c:163:23 gsliepen#1 0x55e3cb7bb7fe in handle_device_data /home/runner/work/tinc/tinc/src/net_packet.c:1906:5 gsliepen#2 0x55e3cb78e6e0 in event_loop /home/runner/work/tinc/tinc/src/event.c:353:5 gsliepen#3 0x55e3cb7a6a90 in main_loop /home/runner/work/tinc/tinc/src/net.c:505:6 gsliepen#4 0x55e3cb83d241 in main /home/runner/work/tinc/tinc/src/tincd.c:614:11 gsliepen#5 0x7fec881950b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2) gsliepen#6 0x55e3cb757dcd in _start (/home/runner/work/tinc/tinc/src/tincd+0x9adcd) SUMMARY: UndefinedBehaviorSanitizer: undefined-behavior linux/device.c:163:23 in

../src/utils.c:141:14: runtime error: implicit conversion from type 'int' of value -1 (32-bit, signed) to type 'unsigned int' changed the value to 4294967295 (32-bit, unsigned) #0 0x478d06 in b64decode_tinc /home/runner/work/tinc/tinc/openssl3/../src/utils.c:141:14 gsliepen#1 0x437f6c in dump_invitations /home/runner/work/tinc/tinc/openssl3/../src/tincctl.c:1116:6 gsliepen#2 0x42ebf6 in cmd_dump /home/runner/work/tinc/tinc/openssl3/../src/tincctl.c:1190:10 gsliepen#3 0x42b4c5 in run_command /home/runner/work/tinc/tinc/openssl3/../src/tincctl.c:3315:11 gsliepen#4 0x42aa24 in main /home/runner/work/tinc/tinc/openssl3/../src/tincctl.c:3366:15 gsliepen#5 0x7f6fb7a4c082 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x24082) gsliepen#6 0x406e2d in _start (/home/runner/work/tinc/tinc/openssl3/src/tinc+0x406e2d) SUMMARY: UndefinedBehaviorSanitizer: undefined-behavior ../src/utils.c:141:14 in

==36472==ERROR: AddressSanitizer: invalid-pointer-pair: 0x000000e9de00 0x608000000db0 #0 0x4d0658 in timeout_compare /home/runner/work/tinc/tinc/openssl3/../src/event.c:97:7 gsliepen#1 0x55a3af in splay_top_down /home/runner/work/tinc/tinc/openssl3/../src/splay_tree.c:41:13 gsliepen#2 0x559868 in splay_search_closest_node /home/runner/work/tinc/tinc/openssl3/../src/splay_tree.c:378:9 gsliepen#3 0x55cd54 in splay_insert_node /home/runner/work/tinc/tinc/openssl3/../src/splay_tree.c:446:13 gsliepen#4 0x4cecfc in timeout_set /home/runner/work/tinc/tinc/openssl3/../src/event.c:267:6 gsliepen#5 0x4d3c49 in retry /home/runner/work/tinc/tinc/openssl3/../src/net.c:477:2 gsliepen#6 0x53f274 in control_h /home/runner/work/tinc/tinc/openssl3/../src/control.c:96:3 gsliepen#7 0x500a44 in receive_request /home/runner/work/tinc/tinc/openssl3/../src/protocol.c:180:7 gsliepen#8 0x5485b2 in receive_meta /home/runner/work/tinc/tinc/openssl3/../src/meta.c:308:19 gsliepen#9 0x4d1c18 in handle_meta_connection_data /home/runner/work/tinc/tinc/openssl3/../src/net.c:305:6 gsliepen#10 0x4fa3cc in handle_meta_io /home/runner/work/tinc/tinc/openssl3/../src/net_socket.c:560:3 gsliepen#11 0x4cfbe3 in event_loop /home/runner/work/tinc/tinc/openssl3/../src/event.c:453:5 gsliepen#12 0x4d4127 in main_loop /home/runner/work/tinc/tinc/openssl3/../src/net.c:508:6 gsliepen#13 0x4cbe24 in main /home/runner/work/tinc/tinc/openssl3/../src/tincd.c:702:11 gsliepen#14 0x7f1900c1e082 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x24082) gsliepen#15 0x41eafd in _start (/home/runner/work/tinc/tinc/openssl3/src/tincd+0x41eafd) 0x000000e9de00 is located 0 bytes inside of global variable 'pingtimer' defined in '../src/net.c:44:18' (0xe9de00) of size 80 0x608000000db0 is located 16 bytes inside of 96-byte region [0x608000000da0,0x608000000e00) allocated by thread T0 here: #0 0x499ed2 in calloc (/home/runner/work/tinc/tinc/openssl3/src/tincd+0x499ed2) gsliepen#1 0x4fc6a9 in xzalloc /home/runner/work/tinc/tinc/openssl3/../src/xalloc.h:41:12 gsliepen#2 0x4fbfb0 in try_outgoing_connections /home/runner/work/tinc/tinc/openssl3/../src/net_socket.c:855:27 gsliepen#3 0x4d31ac in reload_configuration /home/runner/work/tinc/tinc/openssl3/../src/net.c:435:2 gsliepen#4 0x53f2bd in control_h /home/runner/work/tinc/tinc/openssl3/../src/control.c:101:16 gsliepen#5 0x500a44 in receive_request /home/runner/work/tinc/tinc/openssl3/../src/protocol.c:180:7 gsliepen#6 0x5485b2 in receive_meta /home/runner/work/tinc/tinc/openssl3/../src/meta.c:308:19 gsliepen#7 0x4d1c18 in handle_meta_connection_data /home/runner/work/tinc/tinc/openssl3/../src/net.c:305:6 gsliepen#8 0x4fa3cc in handle_meta_io /home/runner/work/tinc/tinc/openssl3/../src/net_socket.c:560:3 gsliepen#9 0x4cfbe3 in event_loop /home/runner/work/tinc/tinc/openssl3/../src/event.c:453:5 gsliepen#10 0x4d4127 in main_loop /home/runner/work/tinc/tinc/openssl3/../src/net.c:508:6 gsliepen#11 0x4cbe24 in main /home/runner/work/tinc/tinc/openssl3/../src/tincd.c:702:11 gsliepen#12 0x7f1900c1e082 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x24082)