Steffen M. DD-WRT User
Joined: 23 Jan 2008 Posts: 50 Location: Ulm, Germany
|
Posted: Mon May 14, 2018 23:32 Post subject: |
|
jwh7 wrote: | Do you have syslog enabled? Also attach: /var/log/messages |
I've enabled it and attached "/var/log/messages".
I haven't expected interesting information from the /var/log/messages, because I have supposed the culprit to be in the driver/kernel, so if there was interesting information, we should have already found it in the kernel ring buffer output (dmesg). As far as I see, there is no interesting information, but maybe someone else detects something of interest.
Nevertheless, it was really worth trying it, because working with real time stamps allowed me to find out for how long the R7000P actually answers broadcasts.
The R7000P was rebooted at May 14, 22:00.
I continuously sent ARP (broadcast) requests which the R7000P has received via its eth2 device. This can be seen in the tcpdump log:
root@wl-ap-eg:~# tcpdump -Q inout -e -u -i any -n not port 23
[...]
23:07:53.904609 00:1e:e5:fe:5d:59 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 398: 192.168.1.67.1900 > 239.255.255.250.1900: UDP, length 356
23:07:53.906395 00:1e:e5:fe:5d:59 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 349: 192.168.1.67.1900 > 239.255.255.250.1900: UDP, length 307
23:07:53.908268 00:1e:e5:fe:5d:59 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 358: 192.168.1.67.1900 > 239.255.255.250.1900: UDP, length 316
23:07:53.910226 00:1e:e5:fe:5d:59 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 405: 192.168.1.67.1900 > 239.255.255.250.1900: UDP, length 363
23:07:53.927673 00:1e:e5:fe:5d:59 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 60: Request who-has 192.168.1.1 tell 192.168.1.66, length 46
23:07:53.929444 1c:1b:0d:9f:5a:c5 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 403: 192.168.1.111.1900 > 239.255.255.250.1900: UDP, length 361
23:07:54.046940 e4:f4:c6:12:93:f3 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 192.168.1.71 tell 192.168.1.1, length 28
23:07:54.322250 1c:1b:0d:9f:5a:c5 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 60: Request who-has 192.168.1.90 tell 192.168.1.111, length 46
23:07:54.585119 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype ARP (0x0806), length 42: Reply 192.168.1.1 is-at e4:f4:c6:12:93:f3, length 28
23:07:54.588552 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 100: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [P.], seq 3832:3866, ack 1816, win 175, options [nop,nop,TS val 4056784938 ecr 137551793], length 34
23:07:54.670050 e4:f4:c6:12:93:f3 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 192.168.1.250 tell 192.168.1.1, length 28
23:07:54.969625 1c:1b:0d:9f:5a:c5 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 419: 192.168.1.111.1900 > 239.255.255.250.1900: UDP, length 377
23:07:54.991738 1c:6f:65:3c:86:1e > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 60: Request who-has 192.168.1.249 tell 192.168.1.101, length 46
23:07:55.060235 e4:f4:c6:12:93:f3 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 192.168.1.71 tell 192.168.1.1, length 28
23:07:55.669133 e4:f4:c6:12:93:f3 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 192.168.1.250 tell 192.168.1.1, length 28
23:07:55.994315 1c:6f:65:3c:86:1e > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 60: Request who-has 192.168.1.249 tell 192.168.1.101, length 46
23:07:56.055912 e4:f4:c6:12:93:f3 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 192.168.1.71 tell 192.168.1.1, length 28
23:07:56.563723 1c:1b:0d:9f:5a:c5 > 01:00:5e:7f:ff:fa, ethertype IPv4 (0x0800), length 431: 192.168.1.111.1900 > 239.255.255.250.1900: UDP, length 389
23:07:56.668396 e4:f4:c6:12:93:f3 > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 192.168.1.250 tell 192.168.1.1, length 28
23:07:56.873002 9e:3d:cf:42:02:fb > 9c:3d:cf:42:02:fb, ethertype Unknown (0x886c), length 205:
0x0000: 8001 00eb 0000 1018 0001 0002 0000 0000 ................
0x0010: 0019 0000 0000 0000 0000 0000 0000 0000 ................
0x0020: 0083 e4f4 c612 93f3 6574 6832 0000 0000 ........eth2....
0x0030: 0000 0000 0000 0000 0000 0203 007f 0213 ................
0x0040: 8200 0000 0000 0000 0000 0300 0000 0000 ................
0x0050: 0000 0000 0000 0000 0000 0000 0000 0000 ................
0x0060: 0000 0000 0000 0000 0000 00c7 562a 094d ............V*.M
0x0070: 0a37 4b20 7127 557d 2928 8b00 0000 0000 .7K.q'U})(......
0x0080: 0000 0000 0000 0000 0000 00dc c4b4 62b4 ..............b.
0x0090: 9b93 f23e f9dd 225b b0f9 2200 204d 7109 ...>.."[.."..Mq.
0x00a0: c44b 4c4a 0e02 fa59 6ff5 b40a e3c9 582b .KLJ...Yo.....X+
0x00b0: 4be3 8546 f14b cfda cfac a980 cb00 00 K..F.K.........
23:07:56.874784 e4:f4:c6:12:93:f3 > 9c:3d:cf:42:02:fb, ethertype EAPOL (0x888e), length 145: EAPOL key (3) v2, len 127
23:08:22.197276 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [.], ack 1852, win 175, options [nop,nop,TS val 4056812507 ecr 137552537], length 0
23:08:22.275251 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 100: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [P.], seq 3866:3900, ack 1852, win 175, options [nop,nop,TS val 4056812625 ecr 137552537], length 34
23:08:49.845678 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [.], ack 1888, win 175, options [nop,nop,TS val 4056840196 ecr 137553167], length 0
23:08:49.854614 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 100: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [P.], seq 3900:3934, ack 1888, win 175, options [nop,nop,TS val 4056840205 ecr 137553167], length 34
23:08:54.862794 1c:6f:65:3c:86:1e > 9c:3d:cf:42:02:f8, ethertype ARP (0x0806), length 60: Request who-has 192.168.1.240 (9c:3d:cf:42:02:f8) tell 192.168.1.101, length 46
23:09:18.601002 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 100: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [P.], seq 3934:3968, ack 1924, win 175, options [nop,nop,TS val 4056868951 ecr 137553670], length 34
23:09:47.585718 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 100: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [P.], seq 3968:4002, ack 1960, win 175, options [nop,nop,TS val 4056897936 ecr 137554136], length 34
23:09:52.606545 1c:6f:65:3c:86:1e > 9c:3d:cf:42:02:f8, ethertype ARP (0x0806), length 60: Request who-has 192.168.1.240 (9c:3d:cf:42:02:f8) tell 192.168.1.101, length 46
23:10:15.599878 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 100: 74.125.133.188.5228 > 192.168.1.31.54379: Flags [P.], seq 4002:4036, ack 1996, win 175, options [nop,nop,TS val 4056925951 ecr 137554533], length 34
23:10:18.373414 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 216.58.206.10.443 > 192.168.1.31.57972: Flags [F.], seq 3682, ack 1243, win 178, options [nop,nop,TS val 2697914085 ecr 137544510], length 0
23:10:18.375201 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 216.58.207.74.443 > 192.168.1.31.53711: Flags [F.], seq 3765, ack 2406, win 194, options [nop,nop,TS val 2891686807 ecr 137544304], length 0
23:10:18.376643 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 172.217.21.238.443 > 192.168.1.31.35683: Flags [F.], seq 1127, ack 1421, win 182, options [nop,nop,TS val 3646723042 ecr 137544233], length 0
23:10:18.378050 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 172.217.21.232.443 > 192.168.1.31.51035: Flags [F.], seq 3693, ack 908, win 175, options [nop,nop,TS val 2024105478 ecr 137545043], length 0
23:10:18.379456 e4:f4:c6:12:93:f3 > c4:f0:81:96:a7:c3, ethertype IPv4 (0x0800), length 66: 172.217.23.170.443 > 192.168.1.31.44338: Flags [F.], seq 1253, ack 1262, win 176, options [nop,nop,TS val 2076960990 ecr 137544426], length 0
Besides other traffic, you can see the ARP requests for the MAC addresses of 192.168.1.249 and 192.168.1.250. My workstation (192.168.1.101) asks for 192.168.1.249 and the AP (R7000, 192.168.1.1) asks for 192.168.1.250. This went on from 22:00 until 23:07:56 (I left out most of the parts here).
At 23:07:56, the R7000P receives an EAPoL key (3) v2 frame, maybe it's related to a WPA2 key change. After this event, the R7000P receives -as you can see- other unicast traffic, but it doesn't see frames to FF:FF:FF:FF:FF:FF anymore... This is where the problem begins.
Doing tcpdump in parallel on the AP, I don't see any change. It still seems to produce the broadcasts.
Other client bridges (WRT600N) connected to the same AP and the same 5 GHz device don't show the problem. Their IP address can still be resolved and DHCP clients "behind" them do still work. Therefore I suppose that the problem lies in the R7000P's driver. Lacking tcpdump on the smaller DD-WRT images of the old WRT600N, I cannot provide a parallel "tcpdump" from their perspective.
So at the moment I can narrow it down to the following working hypothesis: After the R7000P receives an EAPoL frame, it stops detecting any ethernet broadcasts.
Maybe the problem would be gone if I deactivated WPA2...
Thank you very much for looking into this in advance!
Kind regards,
Steffen
Description: |
|
Download |
Filename: |
tcpdump.txt |
Filesize: |
125.08 KB |
Downloaded: |
361 Time(s) |
Description: |
|
Download |
Filename: |
messages.txt |
Filesize: |
33.4 KB |
Downloaded: |
324 Time(s) |
Last edited by Steffen M. on Tue May 15, 2018 16:50; edited 1 time in total |
|