Bug 1434471
| Summary: | cdn-sync continues until 100% even when the connection was lost | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat Satellite 5 | Reporter: | Kenny Tordeurs <ktordeur> | ||||||
| Component: | Satellite Synchronization | Assignee: | Jan Dobes <jdobes> | ||||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Radovan Drazny <rdrazny> | ||||||
| Severity: | low | Docs Contact: | |||||||
| Priority: | unspecified | ||||||||
| Version: | 580 | CC: | dyordano, jdobes, jhutar, ktordeur, rdrazny, tkasparek, tlestach | ||||||
| Target Milestone: | --- | ||||||||
| Target Release: | --- | ||||||||
| Hardware: | Unspecified | ||||||||
| OS: | Unspecified | ||||||||
| Whiteboard: | |||||||||
| Fixed In Version: | spacewalk-backend-2.5.3-111-sat | Doc Type: | If docs needed, set a value | ||||||
| Doc Text: | Story Points: | --- | |||||||
| Clone Of: | Environment: | ||||||||
| Last Closed: | 2017-06-21 12:16:55 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: | |||||||||
| Bug Depends On: | |||||||||
| Bug Blocks: | 1340444 | ||||||||
| Attachments: |
|
||||||||
Hello Kenny, I cannot reproduce the bug with provided steps. If you run cdn-sync w/o parameters, please, show what channels were previously synced. Can you also attach log files of cdnsync? Hello, The sync was ongoing for rhel-x86_64-server-6 so I'll attach the log for that one and cdnsync.log Created attachment 1267853 [details]
cdnsync.log
cdnsync.log
Created attachment 1267854 [details]
rhel-x86_64-server-6.log
rhel-x86_64-server-6.log
bug is fixed in upstream. spacewalk.git: a3fab8dc969acea2a3c077b2e2e9a83d0bce8907 5560aa5fe615a446e868bacb010883182f91ad80 due to regression in BZ#1441135 back to MODIFIED spacewalk.git(master): a3fab8dc969acea2a3c077b2e2e9a83d0bce8907 Tested on Satellite-5.8-RHEL-6-20170522.n.0 using the reproducer from the original report. Started full cdn-sync for rhel-x86_64-server-6, and stopped the satellite services during the "Importing packages" phase, approximately at 25% point. Sync ended with the following output: Importing packages: |##################################################| 100.0% 13:48:21 Linking packages to channel. 13:48:22 ERROR: cursor already closed 13:48:22 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.9/x86_64/kickstart 13:48:25 ERROR: cursor already closed 13:48:25 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.8/x86_64/kickstart 13:48:26 ERROR: cursor already closed 13:48:26 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.6/x86_64/kickstart 13:48:27 ERROR: cursor already closed 13:48:27 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.3/x86_64/kickstart 13:48:28 ERROR: cursor already closed 13:48:28 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.1/x86_64/kickstart 13:48:29 ERROR: cursor already closed 13:48:29 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.4/x86_64/kickstart 13:48:30 ERROR: cursor already closed 13:48:30 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.7/x86_64/kickstart 13:48:31 ERROR: cursor already closed 13:48:31 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.2/x86_64/kickstart 13:48:32 ERROR: cursor already closed 13:48:32 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.5/x86_64/kickstart 13:48:33 ERROR: cursor already closed Traceback (most recent call last): File "/usr/bin/cdn-sync", line 219, in <module> sys.exc_info()[2]) File "/usr/bin/cdn-sync", line 164, in <module> error_messages = cdnsync.sync(channels=args.channel) File "/usr/lib/python2.6/site-packages/spacewalk/cdn_tools/cdnsync.py", line 466, in sync cur_time, failed_packages = self._sync_channel(channel) File "/usr/lib/python2.6/site-packages/spacewalk/cdn_tools/cdnsync.py", line 407, in _sync_channel return sync.sync() File "/usr/lib/python2.6/site-packages/spacewalk/satellite_tools/reposync.py", line 484, in sync """, channel_id=int(self.channel['id'])) or [] File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/__init__.py", line 291, in fetchall_dict h = prepare(sql) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/__init__.py", line 270, in prepare return db.prepare(sql, blob_map=blob_map) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 224, in prepare return Cursor(dbh=self.dbh, sql=sql, force=force, blob_map=blob_map) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 270, in __init__ sql_base.Cursor.__init__(self, dbh, sql, force) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/sql_base.py", line 113, in __init__ self._real_cursor = self._prepare(force=force) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/sql_base.py", line 124, in _prepare cursor = self._prepare_sql() File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 281, in _prepare_sql cursor = self.dbh.cursor() Exception: SYNC ERROR: attempting to display as much information as possible connection already closed cdn-sync still continues to 100% and continues in syncing, albeit much faster than described in the report - whole "failing process" took about 2 minutes. Still, it didn't fail gracefully and continued to a bitter traceback end. FailedQA After discussion with devels, we have decided to create a new bug for current behaviour (cursor errors and traceback). Main problem in the initial report was speed of the process, taking about one hour to finish the failed sync. After the update, whole process of failing is much faster, taking only a few minutes. The new bug regarding the errors and tracebacks was submitted as BZ 1455457. VERIFIED |
Description of problem: cdn-sync keeps trying to sync/import even when the connection is closed Version-Release number of selected component (if applicable): Satellite 5.8 Beta How reproducible: 100% Steps to Reproduce: 1. Start cdn-sync 2. Restart satellite-service or stop db or ... during the sync 3. Actual results: Continues displaying message "server closed the connection unexpectedly" until 100% complete which was +1hour for me Expected results: After "server closed the connection unexpectedly" stop the sync/import process Additional info: 2017/03/21 12:02:04 +02:00 Importing packages started. 2017/03/21 13:25:06 +02:00 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. 2017/03/21 13:25:08 +02:00 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. 2017/03/21 13:25:12 +02:00 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Importing packages: |#################################################-| 10.81% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. ... Importing packages: |#################################################-| 98.81% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Importing packages: |#################################################-| 98.82% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Importing packages: |#################################################-| 98.82% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Importing packages: |#################################################-| 98.83% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Importing packages: |#################################################-| 98.83% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Importing packages: |#################################################-| 98.84% 13:34:56 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. ... 13:35:17 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.2/x86_64/kickstart 13:35:18 ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. 13:35:18 Repo URL: https://cdn.redhat.com/content/dist/rhel/server/6/6.5/x86_64/kickstart 13:35:19 ERROR: server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. Traceback (most recent call last): File "/usr/bin/cdn-sync", line 156, in <module> sys.exc_info()[2]) File "/usr/bin/cdn-sync", line 108, in <module> error_messages = cdnsync.sync(channels=args.channel) File "/usr/lib/python2.6/site-packages/spacewalk/cdn_tools/cdnsync.py", line 310, in sync cur_time, failed_packages = self._sync_channel(channel) File "/usr/lib/python2.6/site-packages/spacewalk/cdn_tools/cdnsync.py", line 285, in _sync_channel return sync.sync() File "/usr/lib/python2.6/site-packages/spacewalk/satellite_tools/reposync.py", line 334, in sync [self.channel_label], [], "server.app.yumreposync") File "/usr/lib/python2.6/site-packages/spacewalk/server/taskomatic.py", line 69, in add_to_repodata_queue_for_channel_package_subscription add_to_repodata_queue(channel, caller, reason[:128]) File "/usr/lib/python2.6/site-packages/spacewalk/server/taskomatic.py", line 53, in add_to_repodata_queue queue.add(entry) File "/usr/lib/python2.6/site-packages/spacewalk/server/taskomatic.py", line 44, in add bypass_filters=self._boolean_as_char(entry.bypass_filters)) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/sql_base.py", line 151, in execute return self._execute_wrapper(self._execute, *p, **kw) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 296, in _execute_wrapper retval = function(*p, **kw) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/sql_base.py", line 205, in _execute return self._execute_(args, kwargs) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 318, in _execute_ self._real_cursor.execute(self.sql, params) Exception: SYNC ERROR: attempting to display as much information as possible server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request.