Solved Strange behavior of fetch when called by system()

skunk · May 4, 2024

When done from the console,
fetch https://download.freebsd.org/ftp/releases/amd64/amd64/13.2-RELEASE/base.txz -o /jails/media/13.2-RELEASE-base.txz
results in:

Code:

-rw-r--r--  1 root  wheel  199975288 Apr  7 07:01:41 2023 13.2-RELEASE-base.txz

When done via Perl system(), fetch always results in a broken downloaded file that tar complains of being of unknown archive format:

Code:

-rw-rw-r--  1 root  wheel  199975367 Apr  7 07:01:41 2023 13.2-RELEASE-base.txz

But, when I use

 wget -qN https://download.freebsd.org/ftp/releases/amd64/amd64/13.2-RELEASE/base.txz -O /jails/media/13.2-RELEASE-base.txz

the result is always correct, no matter whether I call wget from console or via system().

What is the reason why I get these unexpected results with fetch?

richardtoohey2 · May 4, 2024

The second one seems slightly larger - if you hexdump the two files is there an extra header (or footer?)

Or diff the two files and see what’s different - might give you some information on where to look next.

skunk · May 5, 2024

The file is 79 bytes larger when downloaded by fetch via system().
At the first look it seems as if there is added a header and a footer, and the stuff inbetween the actual downloaded file.

Code:

# hd -n 46 13.2-RELEASE-base.txz
00000000  2f 6a 61 69 6c 73 2f 6d  65 64 69 61 2f 31 33 2e  |/jails/media/13.|
00000010  32 2d 52 45 4c 45 41 53  45 2d 62 61 73 65 2e 74  |2-RELEASE-base.t|
00000020  78 7a 20 20 20 20 20 20  20 20 20 20 20 20        |xz            |
0000002e
# hd -s 199975334 13.2-RELEASE-base.txz
0beb61a6  a0 ff ec 03 80 80 80 0c  9d fb 59 80 e0 b1 02 00  |..........Y.....|
0beb61b6  00 3b c1 6f e6 20 ef 72  56 58 00 00 00 00 04 59  |.;.o. .rVX.....Y|
0beb61c6  5a                                                |Z|
0beb61c7
#

As said, I get this result only when doing fetch via system(), with exactly the same parameters as in the console.
With wget this does not happen.
I really feel confused... what could cause this? ?

richardtoohey2 · May 5, 2024

What is the console output of the fetch command? i.e. if you run that fetch command what is the exact output? The “header” looks like the output name from your -o parameter.

EDIT how about if you use -q (quiet) parameter when using fetch?

skunk · May 5, 2024

richardtoohey2 said:
EDIT how about if you use -q (quiet) parameter when using fetch?

This did the trick.
Fetch then refrained from attaching garbage before and after the output file.

Now the question is, why does fetch add bogus data to the downloaded file, rendering it corrupted?
Is it a bug or is it a feature?

cracauer@ · May 5, 2024

skunk said:
This did the trick.
Fetch then refrained from attaching garbage before and after the output file.

Now the question is, why does fetch add bogus data to the downloaded file, rendering it corrupted?
Is it a bug or is it a feature?

Something is messing up file descriptors. Obviously the output file stream ends on up fd 2, which is also used for stderr.

Potentially perl's system() closed fd2 on its fork?

Run truss -f around the perl script.

skunk · May 6, 2024

cracauer@ said:
Obviously the output file stream ends on up fd 2, which is also used for stderr.

If I understand the truss log correctly, then for some reason the open call below returns fd #2 ??? ?
But why? Isn't that one reserved for stderr, to make sure that the result is no mix of data and stderr output?

Code:

37666 113280: write(0,"20240506024726:    callsystem('fetch https://download.freebsd.org/ftp/releases/amd64/amd64/13.2-RELEASE/base.txz -o /jails/media"...,153) = 153 (0x99)

[ system() gets called with the parameters shown in the log write above ]

37666 113280: close(0)                           = 0 (0x0)
37666 113280: pipe2(0x820c3ad98,O_CLOEXEC)       = 0 (0x0)
37666 113280: sigprocmask(SIG_BLOCK,{ SIGCHLD },{ }) = 0 (0x0)
37666 113280: fork()                             = 37675 (0x932b)
37675 100822: <new process>
37675 100822: thr_self(0x825d15000)              = 0 (0x0)
37666 113280: close(1)                           = 0 (0x0)
37666 113280: sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIG
IO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ SIGCHLD }) = 0 (0x0)
37666 113280: sigaction(SIGINT,{ SIG_IGN 0x0 ss_t },{ SIG_IGN 0x0 ss_t }) = 0 (0x0)
37675 100822: sigprocmask(SIG_SETMASK,{ },0x0)   = 0 (0x0)
37666 113280: sigprocmask(SIG_SETMASK,{ SIGCHLD },0x0) = 0 (0x0)
37675 100822: close(0)                           = 0 (0x0)
37666 113280: sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIG
IO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ SIGCHLD }) = 0 (0x0)
37666 113280: sigaction(SIGQUIT,{ SIG_IGN 0x0 ss_t },{ SIG_DFL 0x0 ss_t }) = 0 (0x0)
37666 113280: sigprocmask(SIG_SETMASK,{ SIGCHLD },0x0) = 0 (0x0)
37675 100822: execve("/sbin/fetch",[ "fetch", "https://download.freebsd.org/ftp/releases/amd64/amd64/13.2-RELEASE/base.txz", "-o", "/jails/media/13.2-RELEASE-base.txz" ],[ "PATH=/sbin:/bin:/usr/sbin:/usr/bin:/us
r/local/sbin:/usr/local/bin", ...
[...]

37675 100822: open("/jails/media/13.2-RELEASE-base.txz",O_WRONLY|O_CREAT|O_TRUNC,0666) = 2 (0x2)

[ without quiet option -q the following "header" gets written to the file: ]

37675 100822: write(2,"/jails/media/13.2-RELEASE-base.txz            ",46) = 46 (0x2e)

[ download and writing the data skipped...]

[ finally the following "footer" gets written to the file before it gets closed: ]

37675 100822: write(2,"         190 MB 4826 kBps    40s\n",33) = 33 (0x21)
37675 100822: fstatat(AT_FDCWD,"/jails/media/13.2-RELEASE-base.txz",{ mode=-rw-rw-r-- ,inode=2,size=199974991,blksize=131072 },0x0) = 0 (0x0)
37675 100822: write(2,"\^\\M^Wt\^Z\M-f\M-]\rM\0,\M-D\M-z\M-\\^B\M^@\M^@\M^@\f\M-.\M^S\M-G\^C\M^@\M^@\M^@\f\M-*\M^F\M-C\^A\M^@\M^@\M^@\f\M->\M-&\M-&\^A"...,376) = 376 (0x178)
37675 100822: utimes("/jails/media/13.2-RELEASE-base.txz",{ 1680843701.000000, 1680843701.000000 }) = 0 (0x0)
37675 100822: write(0,"\^W\^C\^C\0\^S\^Q\M-um}\M-X\n\M-2\M^MA\M-`\M-gs\M^Y\M-H\M-#\M-X\M-9\M-C\M-r",24) = 24 (0x18)
37675 100822: close(0)                           = 0 (0x0)
37675 100822: close(2)                           = 0 (0x0)
37675 100822: close(1)                           = 0 (0x0)
37675 100822: exit(0x0)                        
37675 100822: process exit, rval = 0

skunk · May 6, 2024

So the better fix was to make sure that stderr is open before doing the system() call...

Code:

logit( "callsystem('$sy')");
open STDERR, '>/dev/null';
my $syr = system( $sy);

richardtoohey2 · May 6, 2024

How exactly are you using system() in Perl? Looks like there are two modes, one that goes via shell and another that doesn't. (Long time since I used Perl though.)

cracauer@ · May 7, 2024

Fd 2 is not magical and not reserved. It is hardcoded in the program to be used for diagnostic output. But nothing keeps anybody from closing it, in which case it will be returned to the pool of fds to be used on new open() calls.

zirias@ · May 7, 2024

What cracauer@ said. That's why it's recommended practice for a daemon to not only close fds 0-2, but open /dev/null and dup2(2) it to these fds, avoiding any accidental mixup from code written in the expectation of having the stdio file descriptors.

There's actually some "indirection" available in POSIX C which defines STDIN_FILENO etc, but they're just for readability, they must have the constant values 0-2.

Regarding the issue here, perl's system should probably make sure these fds point to "something reasonable" (either a pipe when getting the command's output is desired, or the current fds of the perl interpreter itself, or as a last resort /dev/null), but it seems it doesn't do this and leaves it to the perl programmer ?