Unreachable: https://repo.turris.cz/omnia/lists/base.lua

mkyral · June 19, 2019, 3:17pm

Unfortunatelly I’m not a network guy, so I have no idea what is wrong with ipv6 routing on TO.

Ipv6 routes on client:

[17:12:19 marian@worker ~]$ ip -6 route show 
2001:470:6e:7b6::/64 dev wlp3s0 proto kernel metric 256 pref medium
fdb9:7e41:6092::/64 dev wlp3s0 proto kernel metric 256 pref medium
fe80::/64 dev wlp3s0 proto kernel metric 256 pref medium
ff00::/8 dev wlp3s0 metric 256 pref medium
default via fe80::da58:d7ff:fe00:a188 dev wlp3s0 proto ra metric 1024 mtu 1480 hoplimit 64 pref medium

Ipv6 routes on TO:

root@turris:~# ip -6 route show 
default from 2001:470:6e:7b6::/64 dev 6in4-wan6  proto static  metric 1024 
2001:470:6e:7b6::/64 dev br-lan  proto static  metric 1024 
unreachable 2001:470:6e:7b6::/64 dev lo  proto static  metric 2147483647  error -113
fdb9:7e41:6092::/64 dev br-lan  proto static  metric 1024 
unreachable fdb9:7e41:6092::/48 dev lo  proto static  metric 2147483647  error -113
fe80::/64 dev br-lan  proto kernel  metric 256 
fe80::/64 dev wlan1  proto kernel  metric 256 
fe80::/64 dev wlan0  proto kernel  metric 256 
fe80::/64 dev eth1  proto kernel  metric 256 
fe80::/64 dev 6in4-wan6  proto kernel  metric 256 
fe80::/64 dev veth06TGCD  proto kernel  metric 256

anon50890781 · June 19, 2019, 3:21pm

There cannot be anything wrong with the routing in general as otherwise opkg update would definitely fail too

Why it works however and pkgupdate not is a mystery to me and perhaps can be explained by a developer.

Well, it does not solve the matter but at least you were able to get the update with ipv6 connectivity (somehow)

mkyral · June 19, 2019, 3:36pm

I’m not sure. There are several interfaces in TO that are connected to different networks and setting could differs. It seems like there is issue with localhost - ipv6 wan bridge. Or something like this.

anon50890781 · June 19, 2019, 3:42pm

next time this happens perhaps run pkgupdate -e DBG (or pkgupdate -s DBG if you prefer the output to syslog instead) and if it fails compare the output to opkg update -V3, or submit respective outputs to the developers.

Both are executed in debug mode and the output might reveal what is happening behind the scenes - why one works and the other fails.

mkyral · June 19, 2019, 3:47pm

root@turris:~# pkgupdate -e DBG
DEBUG:src/lib/events.c:586 (run_util_init):Dumping busybox to: /tmp/updater-busybox-gnMplm/busybox
DEBUG:src/lib/locks.c:45 (lua_acquire):Trying to get a lock at /var/lock/opkg.lock
DEBUG:backend.lua:358 (status_parse):Parsing status file /usr/lib/opkg/status
DEBUG:src/lib/interpreter.c:323 (lua_run_generic):Command: /usr/bin/atsha204cmd serial-number 
DEBUG:requests.lua:441 (func):Running script file:////etc/updater/conf.d/base.lua
DEBUG:requests.lua:441 (func):Running script https://repo.turris.cz/omnia/lists/base.lua
DEBUG:src/lib/events.c:823 (download):Downloading https://repo.turris.cz/omnia/lists/base.lua.sig
DEBUG:src/lib/events.c:823 (download):Downloading https://repo.turris.cz/omnia/lists/base.lua
DEBUG:src/lib/events.c:727 (download_check_info):Download failed, trying again 1 (https://repo.turris.cz/omnia/lists/base.lua.sig): Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
DEBUG:src/lib/events.c:727 (download_check_info):Download failed, trying again 1 (https://repo.turris.cz/omnia/lists/base.lua): Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
DEBUG:src/lib/events.c:727 (download_check_info):Download failed, trying again 2 (https://repo.turris.cz/omnia/lists/base.lua.sig): Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
DEBUG:src/lib/events.c:727 (download_check_info):Download failed, trying again 2 (https://repo.turris.cz/omnia/lists/base.lua): Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
DEBUG:src/lib/events.c:735 (download_check_info):Download failed (https://repo.turris.cz/omnia/lists/base.lua.sig): Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
DEBUG:src/lib/events.c:735 (download_check_info):Download failed (https://repo.turris.cz/omnia/lists/base.lua): Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
line not found
line not found
line not found
ERROR:src/pkgupdate/main.c:255 (main):
unreachable: https://repo.turris.cz/omnia/lists/base.lua: Operation timed out after 30000 milliseconds with 0 out of 0 bytes received
DEBUG:src/lib/locks.c:82 (lua_lock_release):Released lock at /var/lock/opkg.lock
DEBUG:src/lib/events.c:604 (run_util_clean):Removing temporally busybox from: /tmp/updater-busybox-gnMplm/busybox

anon50890781 · June 19, 2019, 3:56pm

Just for completeness - if you put https://repo.turris.cz/omnia/lists in a client’s browser’s url bar can you surf the site?

I had recently a lengthy discussion with @cynerd about this and he reckons this being caused by some NAT64

mkyral · June 19, 2019, 4:04pm

Yes. It works as expected. Only problem with ipv6 is directly on router.

Can I somehow check, that there is NAT64 on my ISP network? IPv6 does not work without tunnel.

anon50890781 · June 19, 2019, 4:07pm

with a tcpdump on the router’s wan iface and then packet inspection with a suitable tool like wireshark

mkyral · June 19, 2019, 4:12pm

Hmm. I only know, that something like this exists. But newer used it.

EDIT: should be wan or wan6?

anon50890781 · June 19, 2019, 4:22pm

6in4 is apparently different in that it encapsulates the ipv6 traffic in the ipv4 packet header whilst in in NAT64 the ipv4 address gets embedded with the ipv6 address.

Yet not sure how the HE endpoint is handling its traffic routing.

mkyral · June 19, 2019, 4:33pm

Well to summarize:

I’m able to ssh via IPv6 from client to TO and from TO back to client.
I’m able access outside ipv6 servers from clients (even from debian running in LXC on TO).
I can’t access outside ipv6 servers directly from TO.

anon50890781 · June 19, 2019, 4:34pm

These are netifd’s virtual ifaces, just select the physical one, suppose that eth1 in TOS3.x

Suggest to write the dump to /tmp unless you have added a hard-drive to the TO.

e.g. tcpdump -i eth1 -KXXevvvw /tmp/tcpdump

you need a second ssh session apparently for running pkgupdate whilst tcmpdump is running. stop/escape tcmpdump with crtl+c

mkyral · June 19, 2019, 4:52pm

I’ve tried this:

    root@turris:~# tcpdump -i eth1 |grep 2001:1488:ac15:ff80::69
    tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
    listening on eth1, link-type EN10MB (Ethernet), capture size 262144 bytes
    18:42:40.109413 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842 > 2001:1488:ac15:ff80::69.443: Flags [.], ack 3458442267, win 501, options [nop,nop,TS val 2226227312 ecr 159683456], length 0
    18:42:40.127826 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842: Flags [.], ack 1, win 551, options [nop,nop,TS val 159686016 ecr 2226206952], length 0
    18:42:40.991959 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 tunnel306502.tunnel.tserv27.prg1.ipv6.he.net.57590 > 2001:1488:ac15:ff80::69.443: Flags [S], seq 4047493447, win 28400, options [mss 1420,sackOK,TS val 85724247 ecr 0,nop,wscale 7], length 0
    18:42:41.983856 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 tunnel306502.tunnel.tserv27.prg1.ipv6.he.net.57590 > 2001:1488:ac15:ff80::69.443: Flags [S], seq 4047493447, win 28400, options [mss 1420,sackOK,TS val 85724347 ecr 0,nop,wscale 7], length 0
    18:42:42.157423 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33870 > 2001:1488:ac15:ff80::69.443: Flags [.], ack 1315294399, win 501, options [nop,nop,TS val 2226229360 ecr 159683952], length 0
    18:42:42.158365 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33730 > 2001:1488:ac15:ff80::69.443: Flags [.], ack 714959533, win 1362, options [nop,nop,TS val 2226229361 ecr 159683933], length 0
    18:42:42.165130 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33870: Flags [.], ack 1, win 273, options [nop,nop,TS val 159686528 ecr 2226208996], length 0
    18:42:42.166111 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33730: Flags [.], ack 1, win 1439, options [nop,nop,TS val 159686528 ecr 2226218978], length 0
    18:42:43.983808 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 tunnel306502.tunnel.tserv27.prg1.ipv6.he.net.57590 > 2001:1488:ac15:ff80::69.443: Flags [S], seq 4047493447, win 28400, options [mss 1420,sackOK,TS val 85724547 ecr 0,nop,wscale 7], length 0
    18:42:44.856843 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842 > 2001:1488:ac15:ff80::69.443: Flags [.], seq 1:1409, ack 1, win 501, options [nop,nop,TS val 2226232059 ecr 159686016], length 1408
    18:42:44.856873 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842 > 2001:1488:ac15:ff80::69.443: Flags [P.], seq 1409:1539, ack 1, win 501, options [nop,nop,TS val 2226232059 ecr 159686016], length 130
    18:42:44.875392 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842: Flags [.], ack 1539, win 575, options [nop,nop,TS val 159687203 ecr 2226232059], length 0
    18:42:44.884023 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842: Flags [P.], seq 1:794, ack 1539, win 575, options [nop,nop,TS val 159687205 ecr 2226232059], length 793
    18:42:44.885078 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842 > 2001:1488:ac15:ff80::69.443: Flags [.], ack 794, win 495, options [nop,nop,TS val 2226232088 ecr 159687205], length 0
    18:43:03.297115 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842 > 2001:1488:ac15:ff80::69.443: Flags [.], seq 1539:2947, ack 794, win 501, options [nop,nop,TS val 2226250500 ecr 159689729], length 1408
    18:43:03.297146 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33842 > 2001:1488:ac15:ff80::69.443: Flags [P.], seq 2947:3053, ack 794, win 501, options [nop,nop,TS val 2226250500 ecr 159689729], length 106
    18:43:27.726009 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33870 > 2001:1488:ac15:ff80::69.443: Flags [.], ack 1171, win 501, options [nop,nop,TS val 2226274928 ecr 159695403], length 0
    18:43:27.733729 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33870: Flags [.], ack 2985, win 319, options [nop,nop,TS val 159697920 ecr 2226264867], length 0
    18:44:22.510615 IP 188-175-41-253.client.rionet.cz > tserv1.prg1.he.net: IP6 2001:470:6e:7b6:fef8:aeff:fe36:218a.33730 > 2001:1488:ac15:ff80::69.443: Flags [.], ack 2756, win 1362, options [nop,nop,TS val 2226329712 ecr 159709095], length 0
    18:44:22.518324 IP tserv1.prg1.he.net > 188-175-41-253.client.rionet.cz: IP6 2001:1488:ac15:ff80::69.443 > 2001:470:6e:7b6:fef8:aeff:fe36:218a.33730: Flags [.], ack 8076, win 1439, options [nop,nop,TS val 159711616 ecr 2226319627], length 0

On second session I’ve started the wget command above. The last two rows were received after wget failed on timeout. I’ve no idea what these rows shows

Now I’m trying command you posted.

anon50890781 · June 19, 2019, 5:00pm

These long outputs sort of clutter the thread, imho. May I suggest that you utilize the hide details option from the message window (upper right menu) to post long outputs?

the screen output does not help in this case. the dump needs to be written to a file and the file then to be downloaded to a client with a suitable tool for inspection, like mentioned wireshark. Latter has excellent filtering capabilities but I am afraid there is little learning curve involved of how to best utilize it. It can feel slightly overwhelming looking at a packet dump for the first time

mkyral · June 19, 2019, 5:11pm

I’ve 40MB file loaded in wireshark. Don’t know what to do now.

Edit: there is no repo.turris.cz address 2001:1488:ac15:ff80::69 nor tunnel endpoind ipv4 address: 216.66.86.122

I can send you the file (or FF Send link) via another channel if you want.

vcunat · June 20, 2019, 6:36am

NAT64: I don’t know much about these v4 vs. v6 mechanisms, but I’m certain that NAT64 is meant for a completely different situation where the network towards end users has no IPv4 (only IPv6) and there you need to tunnel IPv4 over IPv6.

anon50890781 · June 20, 2019, 7:06am

And hence the dump is void of any NAT64 indication and thus can be ruled out as cause. But it needed to be investigated if only to be ruled out.

The caveat with tcpdump is that it cannot/does not provide information on the PID that generates the packets and thus makes debugging a bit difficult sometimes.

That said the packet dump reveals that ipv6 connection requests (tcp flag S) to repo.turris.cz (canonical name = proxy.turris.cz) are made to dest port 443 but only (and strangely) in plain tcp and not TLS as it probably should be.

Subsequent the (3) connection attempts appear to be failing as it likely can be expected

details of the packet that makes the connection request

Internet Protocol Version 4, Src: 188.175.41.253, Dst: 216.66.86.122
0100 … = Version: 4
… 0101 = Header Length: 20 bytes (5)
Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
0000 00… = Differentiated Services Codepoint: Default (0)
… …00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
Total Length: 100
Identification: 0x8fc1 (36801)
Flags: 0x4000, Don’t fragment
0… … … … = Reserved bit: Not set
.1… … … … = Don’t fragment: Set
…0. … … … = More fragments: Not set
…0 0000 0000 0000 = Fragment offset: 0
Time to live: 64
Protocol: IPv6 (41)
Header checksum: 0x9546 [validation disabled]
[Header checksum status: Unverified]
Source: 188.175.41.253
Destination: 216.66.86.122
Internet Protocol Version 6, Src: 2001:470:6e:7b6::1, Dst: 2001:1488:ac15:ff80::69
0110 … = Version: 6
… 0000 0000 … … … … … = Traffic Class: 0x00 (DSCP: CS0, ECN: Not-ECT)
… … … 1100 1011 1100 1000 1001 = Flow Label: 0xcbc89
Payload Length: 40
Next Header: TCP (6)
Hop Limit: 64
Source: 2001:470:6e:7b6::1
Destination: 2001:1488:ac15:ff80::69
Transmission Control Protocol, Src Port: 58232, Dst Port: 443, Seq: 0, Len: 0
Source Port: 58232
Destination Port: 443
[Stream index: 28]
[TCP Segment Len: 0]
Sequence number: 0 (relative sequence number)
[Next sequence number: 0 (relative sequence number)]
Acknowledgment number: 0
1010 … = Header Length: 40 bytes (10)
Flags: 0x002 (SYN)
000. … … = Reserved: Not set
…0 … … = Nonce: Not set
… 0… … = Congestion Window Reduced (CWR): Not set
… .0… … = ECN-Echo: Not set
… …0. … = Urgent: Not set
… …0 … = Acknowledgment: Not set
… … 0… = Push: Not set
… … .0… = Reset: Not set
… … …1. = Syn: Set
[Expert Info (Chat/Sequence): Connection establish request (SYN): server port 443]
[Connection establish request (SYN): server port 443]
[Severity level: Chat]
[Group: Sequence]
… … …0 = Fin: Not set
[TCP Flags: ··········S·]
Window size value: 28400
[Calculated window size: 28400]
Checksum: 0x9371 [unverified]
[Checksum Status: Unverified]
Urgent pointer: 0
Options: (20 bytes), Maximum segment size, SACK permitted, Timestamps, No-Operation (NOP), Window scale
TCP Option - Maximum segment size: 1420 bytes
Kind: Maximum Segment Size (2)
Length: 4
MSS Value: 1420
TCP Option - SACK permitted
Kind: SACK Permitted (4)
Length: 2
TCP Option - Timestamps: TSval 85797513, TSecr 0
Kind: Time Stamp Option (8)
Length: 10
Timestamp value: 85797513
Timestamp echo reply: 0
TCP Option - No-Operation (NOP)
Kind: No-Operation (1)
TCP Option - Window scale: 7 (multiply by 128)
Kind: Window Scale (3)
Length: 3
Shift count: 7
[Multiplier: 128]
[Timestamps]
[Time since first frame in this TCP stream: 0.000000000 seconds]
[Time since previous frame in this TCP stream: 0.000000000 seconds]

I would not know how the transport/tls provider (curl / llibopenssl ?) for pkgupdate is supposed to handle a failure in ipv6 connectivity - perhaps fall back to ipv4?

And it still does not explain why pkgupdate fails whereas opkg update works (as observed/reported above in this thread by 2 users), unless pkgupdate has a different transport mechanism than opkg or misses to invoke TLS on ipv6 connectivity.

Maybe the output of openssl s_client -connect repo.turris.cz:443 -debug -msg -nbio_test could shed some light?

mkyral · June 20, 2019, 8:37am

Thanks for the analyze. Will test it evening. (if I don’t forget)

I think that opkg update works because it fallbacks to ipv4 (or use ipv4 by default as it is really quick).

anon50890781 · June 20, 2019, 12:04pm

for extended debugging perhaps worth to split into ipv4/6

openssl s_client -6 -connect repo.turris.cz:443 -debug -msg -nbio_test
openssl s_client -4 -connect repo.turris.cz:443 -debug -msg -nbio_test

mkyral · June 20, 2019, 12:54pm

Will try.

But I’m still wondering why ipv6 works in “Client <-> TO <-> remote url” scenario, but doesn’t work when “client” is Omnia itself ( “TO <-> remote url”).