Bug 78101

Summary: The up2date log has a bug in reporting the times of the events that it records.
Product: [Retired] Red Hat Linux Reporter: Need Real Name <jebates>
Component: up2dateAssignee: Adrian Likins <alikins>
Status: CLOSED CURRENTRELEASE QA Contact: Red Hat Satellite QA List <satqe-list>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.2CC: gafton, mihai.ibanescu
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2003-01-15 05:59:55 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Need Real Name 2002-11-19 02:19:16 UTC
From Bugzilla Helper:
User-Agent: Mozilla/4.78 [en] (X11; U; Linux 2.4.7-10 i686)

Description of problem:
The file /var/log/up2date  records  up2date actions. with time stamps. 
Some sample entries:
[Sun Nov 10 14:00:23 2002] up2date updating login info
[Sun Nov 10 14:00:23 2002] up2date opening rpmdb in /var/lib/rpm/ with option 0
[Sun Nov 10 14:00:23 2002] up2date logging into up2date server
[Sun Nov 10 14:00:23 2002] up2date successfully retrieved authentication token
from up2date server
[Sun Nov 10 14:00:23 2002] up2date Error communicating with server.  The message
There was a network error.  It appears the server has abruptly closed the
[Sun Nov 10 13:33:54 2002] up2date Opening rpmdb in /var/lib/rpm/ with option 0

The problem is that the entry telling about the error was entered long after the
time that it says the event occurred.   (I looked at the log several times after
the preceding entry was recorded - over a span of two hours).   
It is clear that the date times, which log the time down to the second, are
reading the clock at the beginning of a session, recording it somewhere, and
using that time for an entire session.  This makes in impossible to pin down
where the difficulties are occurring when there are repeated transmission
problems on the RHN network.

If you need extensive examples of the  log I can send them, but you should be
able to get them easily by looking at a Linux log from any network up2date
transmission.  (assuming my up2date is no different from others).  I have
observed this behavior as a result of my efforts to understand what is happening
in up2date to determine  whether a more serious bug is causing repeated
transmissions of the same informaton.  Specifically whether   " up2date Opening
rpmdb in /var/lib/rpm/ with option 1"  should always be followed with a clean up
operation getting rid of the files which have been replaced and updating the rpm
list with the newly installed programs.  my current updates seem to be in a

Version-Release number of selected component (if applicable):

How reproducible:

Steps to Reproduce:
1.  I have scheduled Rhn network updates.   I just need to dial up my ISP and
within a couple of hours a download will have occurred which is logged in
/var/log/up2date.  All the entries exhibit this behavior.   Only one time stamp
(to the second) for a long series of events which may take several hours.

Actual Results:  Already described.

Expected Results:  I would expect a time delay between the statement "logging
into up2date server" and "successfully retrieved authentication token from
up2date server" .   I would CERTAINLY expect some elapsed time  before  "Error
communicating with server.  The message was:  There was a network error.  It
appears the server has abruplty (sic) closed the connection."   This elapsed
time varies from a few minutes to a couple of hours.

Additional info:

I included a few lines of output to illustrate the problem

Comment 1 Adrian Likins 2002-12-02 22:05:28 UTC
which version is this?

This bug should be fixed in the latest errata versions