Front page | perl.perl5.porters |
Postings from October 2000
[ID 20001030.005] 5.7.0-7483: Strange socket behaviour
From:
Jens Hamisch
Date:
October 30, 2000 07:45
Subject:
[ID 20001030.005] 5.7.0-7483: Strange socket behaviour
Message ID:
20001030164435.A9682@Strawberry.COM
Hi,
I've figured out a very strange behaviour perl 5.7.0 (APC 7483 installed)
shows on socket read operations. I first found that, when I tried
to run mirror 2.9 using perl 5.7.0 and did some investigation in the
problem. I've isolated the thing in a small client/server application,
with a server which just displays a small text upon being connected
and a variety of client procedures connecting the server.
The server establishes its service on port 4242.
You'll receive the correct text file if you're doing a 'telnet localhost 4242'.
The following small perl program also results in a correct output:
#!/usr/local/bin/perl -w
use FileHandle;
use Client;
my $sh = new FileHandle;
$sh = Client::tcp_connect( 'localhost', 4242);
while( <$sh>) {
print;
}
The module Client.pm provides the appropriate socket and connect
system call.
The next small perl program results in a corrupted output:
#!/usr/local/bin/perl -w
use FileHandle;
use Client;
my $sh = new FileHandle;
$sh = Client::tcp_connect( 'localhost', 4242);
while( !eof( $sh ) ){
my( $res) = &line( $sh );
last if $res eq 'eof';
}
sub line {
my( $fh ) = @_;
while( <$fh> ){
print "$_";
return( "ok" );
}
return( "eof" );
}
Instead of the orginal lines of text a - at a first glance - random
character is displayed at the beginning of each line. Having a closer
look at the things displayed, it turns out, that each of these 'random'
characters form some content of the orginal text file in my case
beginning at character 7317 ... for my point of view this is very, very
mysterious!
Furthermore it turns out, that the first client example does a
connect system call followed by a few read calls as the following
truss output shows:
....
close(4) = 0
connect(3, 0x10022D8E0, 16, 1) = 0
fstat(3, 0xFFFFFFFF7FFFCDA0) = 0
ioctl(3, TCGETA, 0xFFFFFFFF7FFFCCDC) Err#22 EINVAL
read(3, " / * L I N T L I B R A".., 8192) = 8192
ioctl(1, TCGETA, 0xFFFFFFFF7FFFEEAC) Err#25 ENOTTY
fstat(1, 0xFFFFFFFF7FFFEF70) = 0
read(3, " n , i n t y , i n".., 8192) = 8192
read(3, " t ( * i n i t ) ( W I".., 8192) = 8192
read(3, " n t v i d p u t s ( c".., 8192) = 235
write(1, " t ( * i n i t ) ( W I".., 8192) = 8192
read(3, 0x100086C64, 8192) = 0
....
In opposite to this correct behaviour, the second example does lots of
recv calls in addition to the 3 read calls.
....
close(4) = 0
connect(3, 0x10022D8E0, 16, 1) = 0
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF24C, 0xFFFFFFFF7FFFF248, 1) = 0
getsockname(3, 0xFFFFFFFF7FFFEF88, 0xFFFFFFFF7FFFF090, 1) = 0
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF098, 0xFFFFFFFF7FFFF094, 1) = 0
recv(3, " /", 1, 0) = 1
fstat(3, 0xFFFFFFFF7FFFF080) = 0
ioctl(3, TCGETA, 0xFFFFFFFF7FFFEFBC) Err#22 EINVAL
read(3, " * L I N T L I B R A R".., 8192) = 8192
ioctl(1, TCGETA, 0xFFFFFFFF7FFFEE9C) Err#25 ENOTTY
fstat(1, 0xFFFFFFFF7FFFEF60) = 0
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF24C, 0xFFFFFFFF7FFFF248, 1) = 0
getsockname(3, 0xFFFFFFFF7FFFEF88, 0xFFFFFFFF7FFFF090, 1) = 0
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF098, 0xFFFFFFFF7FFFF094, 1) = 0
recv(3, " ,", 1, 0) = 1
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF24C, 0xFFFFFFFF7FFFF248, 1) = 0
getsockname(3, 0xFFFFFFFF7FFFEF88, 0xFFFFFFFF7FFFF090, 1) = 0
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF098, 0xFFFFFFFF7FFFF094, 1) = 0
recv(3, " ", 1, 0) = 1
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF24C, 0xFFFFFFFF7FFFF248, 1) = 0
getsockname(3, 0xFFFFFFFF7FFFEF88, 0xFFFFFFFF7FFFF090, 1) = 0
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF098, 0xFFFFFFFF7FFFF094, 1) = 0
recv(3, " i", 1, 0) = 1
getsockopt(3, 65535, 4104, 0xFFFFFFFF7FFFF24C, 0xFFFFFFFF7FFFF248, 1) = 0
....
Assuming, that the additional eof() call in the second example causes
this behaviour, I did another two tests:
#!/usr/local/bin/perl -w
use FileHandle;
use Client;
my $sh = new FileHandle;
$sh = Client::tcp_connect( 'localhost', 4242);
while( !eof( $sh ) ){
print <$sh>;
}
and
#!/usr/local/bin/perl -w
use FileHandle;
use Client;
my $sh = new FileHandle;
$sh = Client::tcp_connect( 'localhost', 4242);
while( !eof( $sh ) ){
while( <$sh>) {
print;
break;
}
}
The first one worked out fine, while the second one showed the
buggy behaviour! Nevertheless the last test doens't show the
problem, if the 'last' statement is removed!
So my conclusion (without analyzing the underlaying perl code)
is, that caused by the second block of code the 'recv' system calls
are forced and that these 'recv' cause side effects with the
'read' calls.
My perl 5.7.0 environment is:
Summary of my perl5 (revision 5.0 version 7 subversion 0) configuration:
Platform:
osname=solaris, osvers=2.8, archname=sun4-solaris-thread-multi-ld
uname='sunos voi 5.8 generic sun4u sparc sunw,ultra-5_10 '
config_args='-d'
hint=previous, useposix=true, d_sigaction=define
usethreads=define use5005threads=undef useithreads=define usemultiplicity=define
useperlio=undef d_sfio=undef uselargefiles=define usesocks=define
use64bitint=define use64bitall=define uselongdouble=define
Compiler:
cc='cc', ccflags ='-D_REENTRANT -DSOCKS -I/usr/local/include -I/opt/socks5/include -I/usr/local/BerkeleyDB.3.1/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -xarch=v9',
optimize='-g -xarch=v9',
cppflags='-D_REENTRANT -DSOCKS -I/usr/local/include -I/opt/socks5/include -I/usr/local/BerkeleyDB.3.1/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -xarch=v9'
ccversion='Sun WorkShop 6 2000/04/07 C 5.1', gccversion='', gccosandvers=''
intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=87654321
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
ivtype='long', ivsize=8, nvtype='long double', nvsize=16, Off_t='off_t', lseeksize=8
alignbytes=16, usemymalloc=y, prototype=define
Linker and Libraries:
ld='cc', ldflags ='-g -xarch=v9 -L/usr/local/lib -R/usr/local/lib -L/opt/SUNWspro/WS6/lib/v9 -L/opt/socks5/lib -L/usr/local/BerkeleyDB.3.1/lib -R/usr/local/BerkeleyDB.3.1/lib -L/usr/krb5/lib -R/usr/krb5/lib'
libpth=/usr/local/lib /opt/SUNWspro/WS6/lib/v9 /lib /usr/lib /usr/ccs/lib /opt/socks5/lib /usr/local/BerkeleyDB.3.1/lib /usr/krb5/lib
libs=-lsocket -lnsl -ldb -ldl -lm -lsunmath -lposix4 -lpthread -lc -lsec -lsocks5 -lgssapi_krb5
perllibs=-lsocket -lnsl -ldl -lm -lsunmath -lposix4 -lpthread -lc -lsec -lsocks5 -lgssapi_krb5
libc=/usr/lib/sparcv9/libc.so, so=so, useshrplib=true, libperl=libperl.so.7.0
Dynamic Linking:
dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags=' -R /opt/perl_5.7.0/lib/5.7.0/sun4-solaris-thread-multi-ld/CORE'
cccdlflags='-KPIC', lddlflags=' -G -xarch=v9 -L/usr/local/lib -R/usr/local/lib -L/opt/SUNWspro/WS6/lib/v9 -L/opt/socks5/lib -L/usr/local/BerkeleyDB.3.1/lib -R/usr/local/BerkeleyDB.3.1/lib -L/usr/krb5/lib -R/usr/krb5/lib'
Characteristics of this binary (from libperl):
Compile-time options: MULTIPLICITY USE_ITHREADS USE_64_BIT_INT USE_64_BIT_ALL USE_LONG_DOUBLE USE_LARGE_FILES USE_SOCKS PERL_IMPLICIT_CONTEXT
Locally applied patches:
DEVEL7481
Built under solaris
Compiled at Oct 30 2000 13:06:46
@INC:
/opt/perl_5.7.0/lib/5.7.0/sun4-solaris-thread-multi-ld
/opt/perl_5.7.0/lib/5.7.0
/opt/perl_5.7.0/lib/site_perl/5.7.0/sun4-solaris-thread-multi-ld
/opt/perl_5.7.0/lib/site_perl/5.7.0
/opt/perl_5.7.0/lib/site_perl
/opt/perl_5.7.0/lib/vendor_perl/5.7.0/sun4-solaris-thread-multi-ld
/opt/perl_5.7.0/lib/vendor_perl/5.7.0
/opt/perl_5.7.0/lib/vendor_perl
.
I've attached my little 'test-suite' as gzipped tar file to this mail.
Any help of hints would be welcome ...
Regards
-- Jens
--------------------------------------------------------------------------------
/
+##+|##+ STRAWBERRY Jens Hamisch
+v#+v v##+ EDV-Systeme GmbH Managing director
/ v v\v
| . . . | Brauneckweg 2 Car (Voice): (+49 172) 81 04 162
| . | D-82549 Koenigsdorf Voice: (+49 8179) 9305-50
| . | Fax: (+49 8179) 9305-38
\ . / Tel./Fax: (+49 8179) 9305-50 Email: jens@Strawberry.COM
\____/ Strawberry@Strawberry.COM
-
[ID 20001030.005] 5.7.0-7483: Strange socket behaviour
by Jens Hamisch