Netscape-Comm/1.1 server log over-optimistic

Netscape-Comm/1.1 server log over-optimistic

Post by Paul F. Men » Sat, 17 Jun 1995 04:00:00



We are test driving the Netscape-Communications/1.1
server (SunOS 4.1.3) but the logging makes it hard
to evaluate problems with aborted or timed out connections.

Instead of returning the number of bytes actually
sent in the access log, it records the number
of bytes in the requested file, even if few are
transferred.   (The error log reports timeouts but
not bytes transferred, which is helpful info for
large file transfers.)

Bug, feature or zealous over-optimism?  Fix?

-Paul Mende

 
 
 

Netscape-Comm/1.1 server log over-optimistic

Post by Paul F. Mend » Sun, 18 Jun 1995 04:00:00




>>We are test driving the Netscape-Communications/1.1
>>server (SunOS 4.1.3) but the logging makes it hard
>>to evaluate problems with aborted or timed out connections.

>What kind of problems are you seeing? You might want to use sitemon or a more
>appropriate tool besides logging to diagnose such problems.

I suspect they are user, not server, problems judging from the
logs on the NCSA httpd 1.3 server we were running.

There are popular pages with large audio files (1MB and 5MB).
Although the sizes are clearly marked, it appears
some users balk during big transfers:  sometimes there
are one or more successive transfers of 50KB or so,
sometimes followed by a successful transfer and sometimes
not.

The NS-Comm/1.1 logs don't show this and in fact made
the server throughput look much, much higher than it was
because they record 5 MB even if only 0.05 MB is transferred.

I checked that CERN 3.0 does this too but didn't find
a clear spec.  Maybe NCSA http was being unconventional.
What's the right answer?

In any event, the actual bytes transferred is a
helpful number; the file size I already know ;-)
<snip>

Quote:>In general the information in log files should not be taken too heavily. For
>instance, if I have a file that is 32K, under IRIX the default TCP buffer size
>is 61K. That means that the HTTP server will think the entire file was sent
>before the kernel ever actually started sending data (and detected the abort).

That's fine.  However, knowing even the order of magnitude
with NCSA httpd has been helpful in deciphering usage
patterns, organizing content and in estimating
network impact.

Since the NS server seems quite faster than NCSA httpd 1.3,
it would have been interesting to see if users noticed
enough to balk less often.

Paul Mende


 
 
 

Netscape-Comm/1.1 server log over-optimistic

Post by Rob McCoo » Sun, 18 Jun 1995 04:00:00



Quote:>We are test driving the Netscape-Communications/1.1
>server (SunOS 4.1.3) but the logging makes it hard
>to evaluate problems with aborted or timed out connections.

What kind of problems are you seeing? You might want to use sitemon or a more
appropriate tool besides logging to diagnose such problems.

Quote:>Instead of returning the number of bytes actually
>sent in the access log, it records the number
>of bytes in the requested file, even if few are
>transferred.   (The error log reports timeouts but
>not bytes transferred, which is helpful info for
>large file transfers.)

>Bug, feature or zealous over-optimism?  Fix?

It's a fallout from the way we interact with the kernel. Things were done a
certain way for efficiency. Because of the way most UNIX TCP implementations
work, you can't really rely on the byte count an application program returns,
especially when that program is going to close the socket with SO_LINGER turned
off.

In general the information in log files should not be taken too heavily. For
instance, if I have a file that is 32K, under IRIX the default TCP buffer size
is 61K. That means that the HTTP server will think the entire file was sent
before the kernel ever actually started sending data (and detected the abort).

--

Stunt Programmer, Netscape Communications Corporation
It was working ten minutes ago, I swear...

 
 
 

Netscape-Comm/1.1 server log over-optimistic

Post by Simon E Spe » Tue, 20 Jun 1995 04:00:00




Quote:>to evaluate problems with aborted or timed out connections.

>Instead of returning the number of bytes actually
>sent in the access log, it records the number
>of bytes in the requested file, even if few are

>Bug, feature or zealous over-optimism?  Fix?

Paul -

This problem has been noted in all unix servers currently deployed. The problem
is that under unix, it's hard to tell when a transfer is aborted after the
server program has finished writing data to the socket, but before the
data has been sent. Most servers will detect aborted connections IFF the
program is still writing data to the socket; however, in order to detect
failures elsewhere, hackery involving SO_LINGER and waiting for close to
complete is needed - and this still won't tell you just how many bytes were
actually send - just that the connections was aborted.

There are two ways around the problem. The first is to hack the kernel to
report aborted connections, and total amounts written. The other is to do
non-intrusive logging by setting up a packet sniffer on the servers network,
and generating statistics from that. I've done this before, and it gives the
most un-biased statistics, but may be a lot more work than you want for this
situation.

Simon

--
Contract with America - Explained!                      |Phone: +44-81-500-3000

1) To shrink or reduce in size - the economy contracted +-----------------------
2) To become infected -My baby contracted pneumonia when they stopped my welfare

 
 
 

Netscape-Comm/1.1 server log over-optimistic

Post by Rob McCoo » Wed, 21 Jun 1995 04:00:00



Quote:>I checked that CERN 3.0 does this too but didn't find
>a clear spec.  Maybe NCSA http was being unconventional.
>What's the right answer?

The right answer is to make it as accurate as you can, and we'll be working to
make the logfiles more accurate through protocol changes and other such
approaches. As Simon points out, it's hard using the sockets interface to know
for sure how much data was really sent, but we'll make sure to keep concerns
like this at the top of our list. It becomes even more important when ISPs and
other people like that start to use log files to charge users for traffic.

--

Stunt Programmer, Netscape Communications Corporation
It was working ten minutes ago, I swear...

 
 
 

Netscape-Comm/1.1 server log over-optimistic

Post by Andrew Pay » Wed, 21 Jun 1995 04:00:00


    [discussion about HTTP servers correctly logging the bytes delivered
     to the client]

Quote:>You should be able to tell how many bytes were written via the return call
>from write(), shouldn't you?
>The problem might arise in that there could be some data sent but not
>ACK'd, and thus logged but not really used.  With a fine enough resolution
>on the write()s, you could be able to get it within epsilon, though.

>Or am I missing something?

There's a big buffer inside the kernel for each TCP connection to hold
outgoing bytes.  No matter what granularity write()s you use, the kernel
will accept bytes into this buffer, but may not deliver them to the client.
Your server thinks the data got delivered, but the kernel tosses the data
when the client closes/aborts the connection.

--
Andrew Payne                          http://www.openmarket.com/personal/payne
Open Market, Inc.

 
 
 

Netscape-Comm/1.1 server log over-optimistic

Post by Simon E Spe » Thu, 22 Jun 1995 04:00:00





>You should be able to tell how many bytes were written via the return call
>from write(), shouldn't you?
>It seems too simple, but write() returns EPIPE or raises SIGPIPE when the
>reading end of the socket it's writing to is closed, according to my

If that were true, then the problem would be much easier to solve - however
it turns out that buffering stops this from being the case. Writes to a socket
return immediately if there is room in the send buffer - tcp is rsponsible for
making sure the packets actually get written to the net. The EPIPE or SIGPIPE
error/signal is only generated if the close occurs before the program has
finished writing to the socket. This is not usually the case.

Simon
--
Contract with America - Explained!                      |Phone: +44-81-500-3000

1) To shrink or reduce in size - the economy contracted +-----------------------
2) To become infected -My baby contracted pneumonia when they stopped my welfare

 
 
 

1. Netsite Comm Server 1.1 - Environment Variables

I am running Netsite Comm Server 1.1, and am developing a Perl CGI script.  I
am
finding some of the variables, like SERVER_SOFTWARE and SERVER_NAME, have the
correct values, while others like PATH_INFO and PATH_TRANSLATED have nothing    in
them.  I need to determine what HTML page invoked my script - if anyone
knows how to do that pls let me know.
Thanks...

2. I have configuration settings for toshiba 2510cds

3. Netscape 1.1 Multidomain log problem

4. Apache 1.3.1 with Intel chip upgrade

5. Optimizing performance of Netscape Server 1.1 on SGI Challenge S

6. UNIX System V Release 4.2: boottime

7. Netscape commun. server 1.1 and Solaris 2.5

8. GETTING HOSTNAME FROM UTMP

9. UNIX (BSDI 1.1) as a platform for NetScape server??

10. Netscape Mail Server 1.1

11. FS: Netscape Commerce Server 1.1 SOLARIS

12. Netscape Communication server 1.1 under Solaris 2.5

13. fyi: Netscape Server 1.1 & Virtual Domains