Bug 977949

Summary: [BEAKER] Fault: <Fault 1: '<class \'sqlalchemy.exc.OperationalError\'>:(OperationalError)
Product: [Retired] Beaker Reporter: PaulB <pbunyan>
Component: beahAssignee: beaker-dev-list
Status: CLOSED NOTABUG QA Contact: tools-bugs <tools-bugs>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 0.12CC: asaha, bpeck, dcallagh, jburke, llim, pbunyan, qwan, rglasz, rmancy
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-06-25 22:56:54 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description PaulB 2013-06-25 16:11:39 UTC
Description of problem:
 Though the task finished successfully during automated testing, the External Watchdog Expired due to the following:
 Fault: <Fault 1: '<class \'sqlalchemy.exc.OperationalError\'>:(OperationalError)

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

How reproducible:
 Unknown 

Steps to Reproduce:
1. 
  
Actual results:
https://beaker.engineering.redhat.com/jobs/440444
http://beaker-archive.app.eng.bos.redhat.com/beaker-logs/2013/06/4404/440444/927217/console.log
<-SNIP->
2013-06-25 00:02:10,460 beah task_finished: INFO Task 65ecbf8f-a730-4c64-8d4e-197734344922 has finished.  
2013-06-25 00:02:10,463 backend async_proc: INFO Task 13424067 done. Submitting logs...  
2013-06-25 00:02:10,609 backend _send_cmd: INFO Command ['Command', 'forward', 'e45ab910-14c6-43e3-aad1-3f57087ca54c', {'event': ['Event', 'extend_watchdog', '6ae7cf90-b6b5-42de-8f08-59dd34a4d2fb', {'source': 'beah_beaker_backend', 'id': '65ecbf8f-a730-4c64-8serial8250: too much work for irq4 
d4e-197734344922'}, None, {'timeout': 14394}]}] sent.  
2013-06-25 00:02:11,069 backend simple_recipe: ERROR Encoutnered problem while running task '13424067'.  
Traceback (most recent call last):  
  File "/usr/lib/python2.6/site-packages/beah/backends/beakerlc.py", line 510, in simple_recipe  
    result = task.serial8250: too much work for irq4 
getResult()  
  File "/usr/lib/python2.6/site-packages/twisted/internet/defer.py", line 584, in getResult  
    self.result.raiseException()  
  File "/usr/lib/python2.6/site-packages/twisted/internet/defer.py", line 605, in _deferGenerator  
    result = g.serial8250: too much work for irq4 
next()  
  File "/usr/lib/python2.6/site-packages/beah/backends/beakerlc.py", line 591, in _run_task  
    thingy.getResult()  
  File "/usr/lib/python2.6/site-packages/twisted/internet/defer.py", line 584, in getResult  
    self.result.raiseException()  
 serial8250: too much work for irq4 
 File "/usr/lib/python2.6/site-packages/twisted/web/xmlrpc.py", line 307, in parseResponse  
    response = xmlrpclib.loads(contents)[0][0]  
  File "/usr/lib/python2.6/xmlrpclib.py", line 1184, in loads  
    return u.close(), u.getmethodname()  
  File "/userial8250: too much work for irq4 
sr/lib/python2.6/xmlrpclib.py", line 838, in close  
    raise Fault(**self._stack[0])  
Fault: <Fault 1: '<class \'sqlalchemy.exc.OperationalError\'>:(OperationalError) (1054, "Unknown column \'job.group_id\' in \'field list\'") \'SELECT job.id AS job_id, jserial8250: too much work for irq4 
ob.dirty_version AS job_dirty_version, job.clean_version AS job_clean_version, job.owner_id AS job_owner_id, job.group_id AS job_group_id, job.whiteboard AS job_whiteboard, job.retention_tag_id AS job_retention_tag_id, job.product_id AS job_product_id, job.rserial8250: too much work for irq4 
esult AS job_result, job.status AS job_status, job.deleted AS job_deleted, job.to_delete AS job_to_delete, job.ttasks AS job_ttasks, job.ptasks AS job_ptasks, job.wtasks AS job_wtasks, job.ftasks AS job_ftasks, job.ktasks AS job_ktasks \\nFROM job \\nWHERE jserial8250: too much work for irq4 
ob.id = %s\' (440444L,)'>  
<-SNIP->

Expected results:
  Logs submitted successfully for a passing task

Additional info:

Comment 1 Bill Peck 2013-06-25 17:49:49 UTC
To me it looks like all the lab controllers and server were upgraded at once.

I don't know if Nick or Dan have any policy in place for upgrades but upgrades with schema changes should probably happen in this order:

1 - Shut down all services on lab controllers and last on scheduler
2 - Upgrade packages
3 - Apply any schema changes
4 - Restart all services first on scheduler and then all lab controllers.

I leave this bz as a reminder for the beaker devs to communicate this in the upgrade notes. ;-)

Comment 2 Dan Callaghan 2013-06-25 22:56:54 UTC
Looks like you're right Bill, this is not a bug but rather a side effect of yesterday's upgrade.

Coincidentally, I just merged a patch for 0.13.2 which spells out exactly those steps. :-)

http://git.beaker-project.org/cgit/beaker/commit/?h=release-0.13&id=c0f236c63ad0235d3d94f355be9ba93c2a137b0e