Bug 153316 - (it69846_it69830) Mass email from taskomatic due to day light savings time.
Mass email from taskomatic due to day light savings time.
Status: CLOSED CURRENTRELEASE
Product: Red Hat Satellite 5
Classification: Red Hat
Component: Server (Show other bugs)
360
All Linux
medium Severity high
: ---
: ---
Assigned To: Bret McMillan
Fanny Augustin
:
Depends On: 211020
Blocks: 147875 150896 156484 156485 156486 185714 202793
  Show dependency treegraph
 
Reported: 2005-04-04 14:54 EDT by Clifford Perry
Modified: 2007-07-31 11:11 EDT (History)
4 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2005-05-03 23:29:08 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Clifford Perry 2005-04-04 14:54:51 EDT
Description of problem:
For RHN Satellite (3.4 and 3.6) during a 59 minute time period of 1:00am till
1:59am on Sunday April 3rd 2005 TaskOMatic in an attempt to process
RHN::Task::SummaryPopulation encountered an issue where there was already an
entry for the default org_id (of 1) within the rhnDailySummaryQueue table. This
caused a traceback email to be generated and sent to the default email address
specified within the rhn.conf file. Once the error occured taskomatic
automatically rescheduled itself to attempt the same routine again, anf again
encountering the same issue and again sending another email notification. This
looping process was seen within /var/log/messages for taskomatic. 


Version-Release number of selected component (if applicable):
In review I noticed Traceback emails being generated for:
RHN Satellite 3.4 and 3.6
The issue though of re-running the same task over and over again also happened
with all versions of Satellite:
RHN Satellite 2.1, 3.2 and 3.7. 


How reproducible:
Every time

Steps to Reproduce:
1. Login as root, stop all Satellite services
2. use command to reset time/date:
# date 040300552005
# hwclock --systohc --localtime
3. Restart database and all satellite services (inc taskomatic)
4. Wait for 1am to roll by and watch taskomatic generate lots of log entries
within /var/log/messages and email (for 3.4 and 3.6). 
  
Actual results:
It seems that the Schedule::Cron::Events perl module may have a bug within it
and how it handles day light savings time. This issue seems to have occured
because we schedule an event to happen at 2am - which when day light savings
time occurs never happens. As such this perl module attempts to give it an
alternative time and triggers this loop event to occur for the 1:00 -> 1:59am
time period. 
A possible solution is to edit the rhn.conf file and override the current
default entry found within /etc/rhn/defaults/:
web.summary_populator_crontab = 0 2 * * *

with one to schedule the event to happen say at 1:59:
web.summary_populator_crontab = 59 1 * * *


Expected results:


Additional info:
Entries within /var/log/messages for each type of Satellite I reviewed:

* RHN Satellite 2.1
Apr  3 00:40:41 sat-1-04 /usr/sbin/taskomatic[27890]: session_cleanup: 0 stale
sessions deleted
Apr  3 00:55:42 sat-1-04 /usr/sbin/taskomatic[27891]: session_cleanup: 0 stale
sessions deleted
Apr  3 01:00:00 sat-1-04 /usr/sbin/taskomatic[1986]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-04 /usr/sbin/taskomatic[1986]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-04 /usr/sbin/taskomatic[1986]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-04 /usr/sbin/taskomatic[1986]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-04 /usr/sbin/taskomatic[1986]: starting interesting org
hunt ...

* RHN Satellite 3.2
Apr  3 00:33:14 sat-1-06 /usr/sbin/taskomatic[14013]: session_cleanup: 0 stale
sessions deleted
Apr  3 00:48:14 sat-1-06 /usr/sbin/taskomatic[14028]: session_cleanup: 0 stale
sessions deleted
Apr  3 01:00:00 sat-1-06 /usr/sbin/taskomatic[30756]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-06 /usr/sbin/taskomatic[30756]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-06 /usr/sbin/taskomatic[30756]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-06 /usr/sbin/taskomatic[30756]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-06 /usr/sbin/taskomatic[30756]: starting interesting org
hunt ...

* RHN Satellite 3.4
Apr  3 00:36:49 sat-1-08 /usr/sbin/taskomatic[2228]: session_cleanup: 0 stale
sessions deleted
Apr  3 00:51:49 sat-1-08 /usr/sbin/taskomatic[2245]: session_cleanup: 0 stale
sessions deleted
Apr  3 01:00:00 sat-1-08 /usr/sbin/taskomatic[15936]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-08 /usr/sbin/taskomatic[15936]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-08 /usr/sbin/taskomatic[15936]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-08 /usr/sbin/taskomatic[15936]: Execution of task
RHN::Task::SummaryPopulation=HASH(0x8b7c57c) raised exception: RHN::Exception:
DBD::Oracle::db do failed: ORA-00001: unique constraint
(RHNSAT.RHN_DSQUEUE_OID_UQ) violated (DBD ERROR: OCIStmtExecute) [for statement
``INSERT INTO rhnDailySummaryQueue (org_id) VALUES (?)''])   RHN::DB
/usr/lib/perl5/site_perl/5.6.1/i386-linux/RHN/DB.pm 213
RHN::Exception::DB::throw   RHN::DailySummaryEngine
/usr/lib/perl5/site_perl/5.6.1/i386-linux/RHN/DailySummaryEngine.pm 204
RHN::DB::handle_error   RHN::DailySummaryEngine
/usr/lib/perl5/site_perl/5.6.1/i386-linux/RHN/DailySummaryEngine.pm 227
RHN::DailySummaryEngine::enqueue_org   RHN::Task::SummaryPopulation
/usr/lib/perl5/site_perl/5.6.1/i386-linux/RHN/Task/SummaryPopulation.pm 31
RHN::DailySummaryEngine::enqueue_orgs   main /usr/sbin/taskomatic 138
RHN::Task::SummaryPopulation::run   main /usr/sbin/taskomatic 137 (eval) 
Offending Query: INSERT INTO rhnDailySummaryQueue (org_id) VALUES (?)
Apr  3 01:00:00 sat-1-08 /usr/sbin/taskomatic[15936]: starting interesting org
hunt ...

* RHN Satellite 3.6 (Enterprise Linux 3 base OS)
Apr  3 01:00:00 sat-1-10 /usr/sbin/taskomatic[5376]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-10 /usr/sbin/taskomatic[5376]: starting interesting org
hunt ...
Apr  3 01:00:01 sat-1-10 /usr/sbin/taskomatic[5376]: Execution of task
RHN::Task::SummaryPopulation=HASH(0xaa75a84) raised exception: RHN::Exception:
DBD::Oracle::db do failed: ORA-00001: unique constraint
(RHNSAT.RHN_DSQUEUE_OID_UQ) violated (DBD ERROR: OCIStmtExecute) [for Statement
"INSERT INTO rhnDailySummaryQueue (org_id) VALUES (?)"]   RHN::DB
/usr/lib/perl5/site_perl/5.8.0/i386-linux-thread-multi/RHN/DB.pm 215
RHN::Exception::DB::throw   RHN::DailySummaryEngine
/usr/lib/perl5/site_perl/5.8.0/i386-linux-thread-multi/RHN/DailySummaryEngine.pm
204 RHN::DB::handle_error   RHN::DailySummaryEngine
/usr/lib/perl5/site_perl/5.8.0/i386-linux-thread-multi/RHN/DailySummaryEngine.pm
227 RHN::DailySummaryEngine::enqueue_org   RHN::Task::SummaryPopulation
/usr/lib/perl5/site_perl/5.8.0/i386-linux-thread-multi/RHN/Task/SummaryPopulation.pm
31 RHN::DailySummaryEngine::enqueue_orgs   main /usr/sbin/taskomatic 147
RHN::Task::SummaryPopulation::run   main /usr/sbin/taskomatic 146 (eval) 
Offending Query: INSERT INTO rhnDai
Apr  3 01:00:01 sat-1-10 /usr/sbin/taskomatic[5376]: starting interesting org
hunt ...

* RHN Satellite 3.7 (Enterprise Linux 2.1 base OS)
Apr  3 00:59:25 sat-1-20 /usr/sbin/taskomatic[23800]: Finished SynchProbeState run.
Apr  3 01:00:00 sat-1-20 /usr/sbin/taskomatic[23800]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-20 /usr/sbin/taskomatic[23800]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-20 /usr/sbin/taskomatic[23800]: starting interesting org
hunt ...
Apr  3 01:00:00 sat-1-20 /usr/sbin/taskomatic[23800]: finished queueing
interesting orgs for daily summary emails ...
Apr  3 01:00:00 sat-1-20 /usr/sbin/taskomatic[23800]: starting interesting org
hunt ...
Comment 3 Bret McMillan 2005-04-17 22:40:43 EDT
lowest impact fix was to change summary task populator to run by default at 4am
instead of 2am.

Change was applied to the following svn branches:
RELEASE-3_7_0
RELEASE-3_6_0
RELEASE-3_4_0
RELEASE-3_2_0

Change did not apply to RELEASE-2_1_0, as this feature was not present.
Comment 4 Todd Warner 2005-04-20 17:42:43 EDT
mass move to ON_QA
Comment 5 Fanny Augustin 2005-04-21 13:16:11 EDT
Please provide a test plan.  
Comment 6 Bret McMillan 2005-04-22 13:58:02 EDT
Stolen/modified from cliff's comments above:

1. Login as root, stop all Satellite services
2. use command to reset time/date:
# date 040300552005
# hwclock --systohc --localtime
3. Restart database and all satellite services (inc taskomatic)
4. Wait for 1am to roll by and watch nothing happen
5. Wait for 4am and watch the summary population happen as it should... tailing
taskomatic log should provide sufficient info to see it start + stop sans problems.
Comment 7 Fanny Augustin 2005-04-27 16:47:42 EDT
Expected results at 4:00am, something like this in the logs:

Apr 25 02:00:00 rlx-1-24 /usr/sbin/taskomatic[21125]: starting interesting org
hunt ...
Apr 25 02:00:01 rlx-1-24 /usr/sbin/taskomatic[21125]: finished queueing
interesting orgs for daily summary emails ...
Apr 25 02:00:01 rlx-1-24 /usr/sbin/taskomatic[21125]: dealing with org:  1
Apr 25 02:00:01 rlx-1-24 /usr/sbin/taskomatic[21125]: queued emails of org of 0
users in 1.28746032714844e-05s ...
Apr 25 02:00:01 rlx-1-24 /usr/sbin/taskomatic[21125]: org 1 emails sent
Apr 25 02:00:01 rlx-1-24 /usr/sbin/taskomatic[21125]: org 1 removed from queue
Comment 8 Fanny Augustin 2005-04-27 17:28:56 EDT
Looks good on QA.
Comment 10 Fanny Augustin 2005-05-03 23:29:08 EDT
Looks good on Prod

Note You need to log in before you can comment on or make changes to this bug.