bug#42927: Weird error on guix download ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz

bug#42927: Weird error on guix download ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz

[Danny Milosavljevic]

[-- Attachment #1: Type: text/plain, Size: 5479 bytes --]

Hi,

I get the following weird error on

  guix download ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz

Starting download of /tmp/guix-file.PnA5jm
From ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz...
In procedure connect*: Permission denied
failed to download "/tmp/guix-file.PnA5jm" from "ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz"
guix download: error: ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz: download failed

strace -f -s 0:

[pid 16141] connect(16, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = 0
[pid 16141] sendto(16, ""..., 21, MSG_NOSIGNAL, NULL, 0) = 21
[pid 16141] poll([...], 1, 5000)        = 1 ([...])
[pid 16141] recvmsg(16, {msg_name=NULL, msg_namelen=0, msg_iov=[...], msg_iovlen=2, msg_control=[{cmsg_len=20, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, cmsg_data=[...]}], msg_controllen=20, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 17
[pid 16141] mmap(NULL, 217032, PROT_READ, MAP_SHARED, 17, 0) = 0x7f8ad32db000
[pid 16141] close(17)                   = 0
[pid 16141] close(16)                   = 0
[pid 16141] openat(AT_FDCWD, "/etc/gai.conf", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 16141] futex(0x7f8ad809b5c4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
[pid 16141] socket(AF_INET, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 16
[pid 16141] connect(16, {sa_family=AF_INET, sin_port=htons(21), sin_addr=inet_addr("8.43.85.97")}, 16) = 0
[pid 16141] getsockname(16, {sa_family=AF_INET, sin_port=htons(57279), sin_addr=inet_addr("192.168.10.207")}, [28->16]) = 0
[pid 16141] close(16)                   = 0
[pid 16141] socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 16
[pid 16141] connect(16, {sa_family=AF_INET6, sin6_port=htons(21), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "2620:52:3:1:0:246e:9693:128c", &sin6_addr), sin6_scope_id=0}, 28) = 0
[pid 16141] getsockname(16, {sa_family=AF_INET6, sin6_port=htons(42412), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "2a02:8388:281:94f0::93b", &sin6_addr), sin6_scope_id=0}, [28]) = 0
[pid 16141] close(16)                   = 0
[pid 16141] socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 16
[pid 16141] fcntl(16, F_GETFL)          = 0x2 (flags O_RDWR)
[pid 16141] fcntl(16, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 16141] connect(16, {sa_family=AF_INET6, sin6_port=htons(21), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "2620:52:3:1:0:246e:9693:128c", &sin6_addr), sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
[pid 16141] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 16141] select(17, [3], [16], [16], {tv_sec=10, tv_usec=0}) = 1 (out [16], left {tv_sec=9, tv_usec=880026})
[pid 16141] fcntl(16, F_SETFL, O_RDWR)  = 0
[pid 16141] getsockopt(16, SOL_SOCKET, SO_ERROR, [0], [8->4]) = 0
[pid 16141] fstat(16, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
[pid 16141] read(16, ""..., 4096)       = 40
[pid 16141] brk(0x1385000)              = 0x1385000
[pid 16141] brk(0x137d000)              = 0x137d000
[pid 16141] brk(0x1375000)              = 0x1375000
[pid 16141] brk(0x136d000)              = 0x136d000
[pid 16141] write(16, ""..., 16)        = 16
[pid 16141] read(16, ""..., 4096)       = 34
[pid 16141] write(16, ""..., 23)        = 23
[pid 16141] read(16, ""..., 4096)       = 23
[pid 16141] write(16, ""..., 8)         = 8
[pid 16141] read(16, ""..., 4096)       = 31
[pid 16141] write(16, ""..., 33)        = 33
[pid 16141] read(16, ""..., 4096)       = 13
[pid 16141] write(16, ""..., 7)         = 7
[pid 16141] read(16, ""..., 4096)       = 37
[pid 16141] write(16, ""..., 9)         = 9
[pid 16141] read(16, ""..., 4096)       = 37
[pid 16141] write(16, ""..., 10)        = 10
[pid 16141] read(16, ""..., 4096)       = 37
[pid 16141] write(16, ""..., 8)         = 8
[pid 16141] read(16, ""..., 4096)       = 31
[pid 16141] write(16, ""..., 6)         = 6
[pid 16141] read(16, ""..., 4096)       = 45
[pid 16141] socket(AF_INET6, SOCK_STREAM, IPPROTO_TCP) = 17
[pid 16141] fcntl(17, F_GETFL)          = 0x2 (flags O_RDWR)
[pid 16141] fcntl(17, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 16141] connect(17, {sa_family=AF_INET6, sin6_port=htons(27421), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "2620:52:3:1:0:246e:9693:128c", &sin6_addr), sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
[pid 16141] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 16141] select(18, [3], [17], [17], {tv_sec=10, tv_usec=0}) = 1 (out [17], left {tv_sec=9, tv_usec=880751})
[pid 16141] fcntl(17, F_SETFL, O_RDWR)  = 0
[pid 16141] getsockopt(17, SOL_SOCKET, SO_ERROR, [EACCES], [8->4]) = 0
[pid 16141] write(2, ""..., 41In procedure connect*: Permission denied
)         = 41
[pid 16141] write(2, ""..., 97failed to download "/tmp/guix-file.X4QpoI" from "ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz"
)         = 97

This error is 100% reproducible every time on my laptop.

But:

$ ping6 2620:52:3:1:0:246e:9693:128c
PING 2620:52:3:1:0:246e:9693:128c (2620:52:3:1:0:246e:9693:128c): 56 data bytes
64 bytes from server2.sourceware.org: icmp_seq=0 ttl=49 time=119,991 ms
$ telnet 2620:52:3:1:0:246e:9693:128c ftp
Trying 2620:52:3:1:0:246e:9693:128c...
Connected to 2620:52:3:1:0:246e:9693:128c.
Escape character is '^]'.
220 Welcome to sourceware FTP service.
$ ncftpget ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz
This one succeeds, but it also uses IPv4 and doesn't use the same IPv6 address 2620:52:3:1:0:246e:9693:128c from above.

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

bug#42927: Weird error on guix download ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz

[Tobias Geerinckx-Rice via Bug reports for GNU Guix]

[-- Attachment #1.1: Type: text/plain, Size: 149 bytes --]

Danny,

As you noticed LVM2, on master now defaults to HTTPS instead of 
FTP.  However, that doesn't actually solve or fix this bug.

FWIW FTP WFM:


[-- Attachment #1.2: Type: text/plain, Size: 372 bytes --]

~/guix master λ guix download 
ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz

Starting download of /tmp/guix-file.J33OOi
From ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz...
 LVM2.2.03.10.tgz  2.4MiB 
 1.2MiB/s 00:02 [##################] 100.0%
/gnu/store/r9g36syz9yhgyx5mjnq6xvdhmfxg8aw4-LVM2.2.03.10.tgz
1l0fkn9abrgk5mfn6jfh9qhdr86b59l1c5pk6lp8jh0491d69las

[-- Attachment #1.3: Type: text/plain, Size: 269 bytes --]


Danny Milosavljevic 写道：
> I get the following weird error on

Does ‘Permission denied’ coming from getsockopt look odd to anyone 
else?  I'm not a network person, but it does not sound like an 
error coming from the network.

Kind regards,

T G-R

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

bug#42927: Weird error on guix download ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz

[Ludovic Courtès]

Hi,

Tobias Geerinckx-Rice via Bug reports for GNU Guix <bug-guix@gnu.org>
skribis:

> FWIW FTP WFM:
>
> ~/guix master λ guix download
> ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz
>
> Starting download of /tmp/guix-file.J33OOi
> From ftp://sourceware.org/pub/lvm2/LVM2.2.03.10.tgz...
> LVM2.2.03.10.tgz  2.4MiB 1.2MiB/s 00:02 [##################] 100.0%
> /gnu/store/r9g36syz9yhgyx5mjnq6xvdhmfxg8aw4-LVM2.2.03.10.tgz
> 1l0fkn9abrgk5mfn6jfh9qhdr86b59l1c5pk6lp8jh0491d69las

I get ETIMEDOUT:

--8<---------------cut here---------------start------------->8---
fstat(16, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
read(16, "220 Welcome to sourceware FTP se"..., 4096) = 40
write(16, "USER anonymous\r\n", 16)     = 16
read(16, "331 Please specify the password."..., 4096) = 34
write(16, "PASS guix@example.com\r\n", 23) = 23
read(16, "230 Login successful.\r\n", 4096) = 23
write(16, "TYPE I\r\n", 8)              = 8
read(16, "200 Switching to Binary mode.\r\n", 4096) = 31
write(16, "SIZE /pub/lvm2/LVM2.2.03.10.tgz\r"..., 33) = 33
read(16, "213 2510568\r\n", 4096)       = 13
write(16, "CWD /\r\n", 7)               = 7
read(16, "250 Directory successfully chang"..., 4096) = 37
write(16, "CWD pub\r\n", 9)             = 9
read(16, "250 Directory successfully chang"..., 4096) = 37
write(16, "CWD lvm2\r\n", 10)           = 10
read(16, "250 Directory successfully chang"..., 4096) = 37
write(16, "TYPE I\r\n", 8)              = 8
read(16, "200 Switching to Binary mode.\r\n", 4096) = 31
write(16, "PASV\r\n", 6)                = 6
read(16, "227 Entering Passive Mode (0,0,0"..., 4096) = 46
socket(AF_INET6, SOCK_STREAM, IPPROTO_TCP) = 17
fcntl(17, F_GETFL)                      = 0x2 (flags O_RDWR)
fcntl(17, F_SETFL, O_RDWR|O_NONBLOCK)   = 0
connect(17, {sa_family=AF_INET6, sin6_port=htons(49263), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "2620:52:3:1:0:246e:9693:128c", &sin6_addr), sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operacio nun fariĝas)
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
select(18, [3], [17], [17], {tv_sec=10, tv_usec=0}) = 0 (Timeout)
write(2, "In procedure connect*: Konekto t"..., 52In procedure connect*: Konekto transpasis limtempon
) = 52
--8<---------------cut here---------------end--------------->8---

Could it be that ‘ftp-pasv’ is not connecting to the right address, or
some IPv6 issue somewhere on the way?

> Danny Milosavljevic 写道：
>> I get the following weird error on
>
> Does ‘Permission denied’ coming from getsockopt look odd to anyone
> else?  I'm not a network person, but it does not sound like an error
> coming from the network.

Yes, that one looks very weird.  Danny?

Ludo’.