Bug 803230 - ISE for scheduled verification of package jpackage-utils-5.0.0-2.jpp5.noarch
Summary: ISE for scheduled verification of package jpackage-utils-5.0.0-2.jpp5.noarch
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Satellite 5
Classification: Red Hat
Component: Server
Version: 550
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Jan Pazdziora
QA Contact: Matej Kollar
URL:
Whiteboard:
Depends On:
Blocks: sat550-blockers sat550-post-ga, sat550-test-blockers
TreeView+ depends on / blocked
 
Reported: 2012-03-14 09:40 UTC by Matej Kollar
Modified: 2012-10-02 10:53 UTC (History)
3 users (show)

Fixed In Version: spacewalk-backend-1.7.38-2
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-10-02 10:53:49 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Matej Kollar 2012-03-14 09:40:24 UTC
Description of problem:

  When verification of package jpackage-utils-5.0.0-2.jpp5.noarch
  (or more packages that includes also this package)
  is scheduled via WebUI and picked up by rhn_check and processed,
  ISE occurs on posting results back:

    XMLRPC ProtocolError: <ProtocolError for <server.fully.qualified.domain> /XMLRPC: 500 Internal Server Error>


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

  Spacewalk 1.7

How reproducible: always/deterministic

Steps to Reproduce:

  1. Install package jpackage-utils-5.0.0-2.jpp5.noarch from jpackage-generic (http://mirrors.dotsrc.org/jpackage/5.0/generic/free/) on client.
  2. Register client into Spacewalk.
  3. Schedule verification of package jpackage-utils.
  4. Run rhn_check (-vv)
  
Actual results:

  rhn_check terminates with error:

    XMLRPC ProtocolError: <ProtocolError for <server.fully.qualified.domain> /XMLRPC: 500 Internal Server Error>

  Scheduled task is still unprocessed so on next rhn_check is picked same task (with same outcome (ISE))

  In apache /var/log/httpd/error_log appears:

[dow mth dd hh:mm:ss yyyy] [error] Exception reported from <server.fully.qualified.domain>
[dow mth dd hh:mm:ss yyyy] [error] Time: Wed Mar 14 05:15:45 2012
[dow mth dd hh:mm:ss yyyy] [error] Exception type <class 'spacewalk.server.rhnSQL.sql_base.SQLStatementPrepareError'>
[dow mth dd hh:mm:ss yyyy] [error] Exception while handling function queue.submit
[dow mth dd hh:mm:ss yyyy] [error] Request object information:
[dow mth dd hh:mm:ss yyyy] [error] URI: /XMLRPC
[dow mth dd hh:mm:ss yyyy] [error] Remote Host: <client.fully.qualified.domain>
[dow mth dd hh:mm:ss yyyy] [error] Server Name: <server.fully.qualified.domain>:443
[dow mth dd hh:mm:ss yyyy] [error] Headers passed in:
[dow mth dd hh:mm:ss yyyy] [error] \tAccept-Encoding: identity
[dow mth dd hh:mm:ss yyyy] [error] \tCONTENT_LENGTH: 3031
[dow mth dd hh:mm:ss yyyy] [error] \tCONTENT_TYPE: text/xml
[dow mth dd hh:mm:ss yyyy] [error] \tDOCUMENT_ROOT: /var/www/html
[dow mth dd hh:mm:ss yyyy] [error] \tGATEWAY_INTERFACE: CGI/1.1
[dow mth dd hh:mm:ss yyyy] [error] \tHTTPS: 1
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_ACCEPT_ENCODING: identity
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_HOST: <server.fully.qualified.domain>
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_USER_AGENT: rhn.rpclib.py/$Revision$
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_X_CLIENT_VERSION: 1
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_X_INFO: RPC Processor (C) Red Hat, Inc (version $Revision$)
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_X_RHN_CLIENT_CAPABILITY: packages.verify(1)=1,packages.extended_profile(2)=1,configfiles.base64_enc(1)=1,reboot.reboot(1)=1,configfiles.deploy(1)=1,caneatCheese(1)=1,packages.rollBack(1)=1,configfiles.mtime_upload(1)=1,configfiles.diff(1)=1,packages.update(2)=2,script.run(1)=1,configfiles.upload(1)=1,packages.runTransaction(1)=1,packages.verify(1)=1,packages.extended_profile(2)=1,configfiles.base64_enc(1)=1,reboot.reboot(1)=1,configfiles.deploy(1)=1,caneatCheese(1)=1,packages.rollBack(1)=1,configfiles.mtime_upload(1)=1,configfiles.diff(1)=1,packages.update(2)=2,script.run(1)=1,configfiles.upload(1)=1,packages.runTransaction(1)=1
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_X_RHN_TRANSPORT_CAPABILITY: follow-redirects=3
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_X_TRANSPORT_INFO: Extended Capabilities Transport (C) Red Hat, Inc (version $Revision$)
[dow mth dd hh:mm:ss yyyy] [error] \tHTTP_X_UP2DATE_VERSION: 1.7.14-1.el6
[dow mth dd hh:mm:ss yyyy] [error] \tHost: <server.fully.qualified.domain>
[dow mth dd hh:mm:ss yyyy] [error] \tPATH_INFO: 
[dow mth dd hh:mm:ss yyyy] [error] \tQUERY_STRING: 
[dow mth dd hh:mm:ss yyyy] [error] \tREMOTE_ADDR: 10.16.64.249
[dow mth dd hh:mm:ss yyyy] [error] \tREMOTE_PORT: 36700
[dow mth dd hh:mm:ss yyyy] [error] \tREQUEST_METHOD: POST
[dow mth dd hh:mm:ss yyyy] [error] \tREQUEST_URI: /XMLRPC
[dow mth dd hh:mm:ss yyyy] [error] \tSCRIPT_FILENAME: /usr/share/rhn/wsgi/xmlrpc.py
[dow mth dd hh:mm:ss yyyy] [error] \tSCRIPT_NAME: /XMLRPC
[dow mth dd hh:mm:ss yyyy] [error] \tSCRIPT_URI: https://<server.fully.qualified.domain>/XMLRPC
[dow mth dd hh:mm:ss yyyy] [error] \tSCRIPT_URL: /XMLRPC
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_ADDR: 10.10.9.234
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_ADMIN: root@localhost
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_NAME: <server.fully.qualified.domain>
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_PORT: 443
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_PROTOCOL: HTTP/1.1
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_SIGNATURE: <address>Apache Server at <server.fully.qualified.domain> Port 443</address>
[dow mth dd hh:mm:ss yyyy] [error] 
[dow mth dd hh:mm:ss yyyy] [error] \tSERVER_SOFTWARE: Apache
[dow mth dd hh:mm:ss yyyy] [error] \tUser-Agent: rhn.rpclib.py/$Revision$
[dow mth dd hh:mm:ss yyyy] [error] \tX-Client-Version: 1
[dow mth dd hh:mm:ss yyyy] [error] \tX-Info: RPC Processor (C) Red Hat, Inc (version $Revision$)
[dow mth dd hh:mm:ss yyyy] [error] \tX-RHN-Client-Capability: packages.verify(1)=1,packages.extended_profile(2)=1,configfiles.base64_enc(1)=1,reboot.reboot(1)=1,configfiles.deploy(1)=1,caneatCheese(1)=1,packages.rollBack(1)=1,configfiles.mtime_upload(1)=1,configfiles.diff(1)=1,packages.update(2)=2,script.run(1)=1,configfiles.upload(1)=1,packages.runTransaction(1)=1,packages.verify(1)=1,packages.extended_profile(2)=1,configfiles.base64_enc(1)=1,reboot.reboot(1)=1,configfiles.deploy(1)=1,caneatCheese(1)=1,packages.rollBack(1)=1,configfiles.mtime_upload(1)=1,configfiles.diff(1)=1,packages.update(2)=2,script.run(1)=1,configfiles.upload(1)=1,packages.runTransaction(1)=1
[dow mth dd hh:mm:ss yyyy] [error] \tX-RHN-Transport-Capability: follow-redirects=3
[dow mth dd hh:mm:ss yyyy] [error] \tX-Transport-Info: Extended Capabilities Transport (C) Red Hat, Inc (version $Revision$)
[dow mth dd hh:mm:ss yyyy] [error] \tX-Up2Date-Version: 1.7.14-1.el6
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.application_group: <server.fully.qualified.domain>|/xmlrpc
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.callable_object: application
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.handler_script: 
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.input_chunked: 0
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.listener_host: 
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.listener_port: 443
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.process_group: 
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.request_handler: wsgi-script
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.script_reloading: 1
[dow mth dd hh:mm:ss yyyy] [error] \tmod_wsgi.version: (3, 2)
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.errors: <mod_wsgi.Log object at 0x7f913b737630>
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.file_wrapper: <built-in method file_wrapper of mod_wsgi.Adapter object at 0x7f9122ef6648>
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.input: <mod_wsgi.Input object at 0x7f913b89c2f0>
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.multiprocess: True
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.multithread: False
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.run_once: False
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.url_scheme: https
[dow mth dd hh:mm:ss yyyy] [error] \twsgi.version: (1, 1)
[dow mth dd hh:mm:ss yyyy] [error] Extra information about this error:
[dow mth dd hh:mm:ss yyyy] [error] SQL Error generated: ("function lookup_evr(integer, unknown, unknown) does not exist\\nLINE 15:       lookup_evr(0, E'5.0.0', E'2.jpp5'),\\n               ^\\nHINT:  No function matches the given name and argument types. You might need to add explicit type casts.\\n", 0, '\\ninsert into rhnServerActionVerifyResult (\\n    server_id, action_id,\\n    package_name_id,\\n    package_evr_id,\\n    package_arch_id,\\n    package_capability_id,\\n    attribute, size_differs, mode_differs, checksum_differs,\\n    devnum_differs, readlink_differs, uid_differs,\\n    gid_differs, mtime_differs\\n)\\nvalues (\\n      %(server_id)s, %(action_id)s,\\n      lookup_package_name(%(package_name)s),\\n      lookup_evr(%(epoch)s, %(version)s, %(release)s),\\n      lookup_package_arch(%(arch)s),\\n      lookup_package_capability(%(filename)s),\\n      %(attrib)s, %(test_S)s, %(test_M)s, %(test_5)s,\\n      %(test_D)s, %(test_L)s, %(test_U)s,\\n      %(test_G)s, %(test_T)s\\n)\\n')
[dow mth dd hh:mm:ss yyyy] [error] 
[dow mth dd hh:mm:ss yyyy] [error] Exception Handler Information
[dow mth dd hh:mm:ss yyyy] [error] Traceback (most recent call last):
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/lib/python2.6/site-packages/spacewalk/server/apacheRequest.py", line 122, in call_function
[dow mth dd hh:mm:ss yyyy] [error]     response = apply(func, params)
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/share/rhn/server/handlers/xmlrpc/queue.py", line 470, in submit
[dow mth dd hh:mm:ss yyyy] [error]     action_type=action_type)
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/share/rhn/server/handlers/xmlrpc/queue.py", line 515, in process_extra_data
[dow mth dd hh:mm:ss yyyy] [error]     result = method(self.server_id, action_id, data=data)
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/lib/python2.6/site-packages/spacewalk/server/action_extra_data/packages.py", line 171, in verify
[dow mth dd hh:mm:ss yyyy] [error]     apply(h.executemany, (), verify_attribs)
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/sql_base.py", line 172, in executemany
[dow mth dd hh:mm:ss yyyy] [error]     return apply(self._execute_wrapper, (self._executemany, ) + p, kw)
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 282, in _execute_wrapper
[dow mth dd hh:mm:ss yyyy] [error]     retval = apply(function, p, kw)
[dow mth dd hh:mm:ss yyyy] [error]   File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 318, in _executemany
[dow mth dd hh:mm:ss yyyy] [error]     self._real_cursor.executemany(self.sql, all_kwargs)
[dow mth dd hh:mm:ss yyyy] [error] SQLStatementPrepareError: ("function lookup_evr(integer, unknown, unknown) does not exist\\nLINE 15:       lookup_evr(0, E'5.0.0', E'2.jpp5'),\\n               ^\\nHINT:  No function matches the given name and argument types. You might need to add explicit type casts.\\n", 0, '\\ninsert into rhnServerActionVerifyResult (\\n    server_id, action_id,\\n    package_name_id,\\n    package_evr_id,\\n    package_arch_id,\\n    package_capability_id,\\n    attribute, size_differs, mode_differs, checksum_differs,\\n    devnum_differs, readlink_differs, uid_differs,\\n    gid_differs, mtime_differs\\n)\\nvalues (\\n      %(server_id)s, %(action_id)s,\\n      lookup_package_name(%(package_name)s),\\n      lookup_evr(%(epoch)s, %(version)s, %(release)s),\\n      lookup_package_arch(%(arch)s),\\n      lookup_package_capability(%(filename)s),\\n      %(attrib)s, %(test_S)s, %(test_M)s, %(test_5)s,\\n      %(test_D)s, %(test_L)s, %(test_U)s,\\n      %(test_G)s, %(test_T)s\\n)\\n')
[dow mth dd hh:mm:ss yyyy] [error] 


Expected results:

  Task is processed, without any ISE, no traceback in error log.

Additional info:

  Running rpm verification over jpackage-utils returns:

    # rpm -qV jpackage-utils
    S.5....T.  c /etc/maven/maven2-depmap.xml

Comment 2 Jan Pazdziora 2012-03-14 15:05:14 UTC
Could you please check if patching your /usr/lib/*/site-packages/spacewalk/server/action_extra_data/packages.py with

--- a/backend/server/action_extra_data/packages.py
+++ b/backend/server/action_extra_data/packages.py
@@ -49,7 +49,7 @@ insert into rhnServerActionVerifyResult (
 values (
       :server_id, :action_id,
       lookup_package_name(:package_name),
-      lookup_evr(:epoch, :version, :release),
+      lookup_evr(:epoch, :version || '', :release || ''),
       lookup_package_arch(:arch),
       lookup_package_capability(:filename),
       :attrib, :test_S, :test_M, :test_5,

and restarting httpd fixes the problem?

Comment 3 Matej Kollar 2012-03-14 15:39:02 UTC
Yes I can. And no it haven't fixed the problem, following change somehow made it work (I was just playing with the thing a little bit):

      lookup_evr(:epoch || '', :version, :release),
 
(I have noticed that there is similar line in that file few lines later (around line 74)... just saying)

Comment 4 Jan Pazdziora 2012-03-14 15:49:08 UTC
Awesome. Fixed in Spacewalk master then, 25739d6af9258404ab314dcb36b5cfb1eb31ba96.

Comment 7 Matej Kollar 2012-06-11 10:48:52 UTC
I have verified that mentioned package is verified ok with spacewalk-backend-1.7.38-17.

Package installed, verification scheduled, event picked. Everything went ok.


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