• Language:

Spacewalk: Failed channel syncs because of duplicate packages

A brief summary:
I’m working with Spacewalk for three years now, from version 2.4 on. We manage about 350 systems, 30 channels, 50 repositories and 105.000 packages. We import new packages and errata on a daily basis, roll out critical patches to stage systems automatically and do weekly/monthly patchdays on productive systems only via Spacewalk.

Lately the periodic syncs of our CentOS 6 x86_64 channel failed on every run. New packages stayed in the queue and could not be rolled out to our systems. The Taskomatic daemon sends out error notification emails to the set administrator mailbox in which it basically tells you that the repo-sync-bunch failed and in which logfile you can read more about this issue.

The error:13:37:56 ERROR: (23, 'ERROR: duplicate key value violates unique constraint "rhn_cnp_cid_nid_uq"', 'Could not update database entry.')
13:37:56 Repo URL: http://mirror.centos.org/centos/6/extras/x86_64/

Traceback (most recent call last):

File "/usr/bin/spacewalk-repo-sync", line 257, in <module>

sys.exit(abs(main() or 0))

File "/usr/bin/spacewalk-repo-sync", line 240, in main

elapsed_time, channel_ret_code = sync.sync()

File "/usr/lib/python2.7/site-packages/spacewalk/satellite_tools/reposync.py", line 453, in sync

""", repo_id=int(repo_id))

File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/__init__.py", line 292, in fetchall_dict

h.execute(sql, *args, **kwargs)

File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/sql_base.py", line 151, in execute

return self._execute_wrapper(self._execute, *p, **kw)

File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 302, in _execute_wrapper

raise sql_base.SQLSchemaError(error_code, e.pgerror, e)

spacewalk.server.rhnSQL.sql_base.SQLSchemaError: (99999, 'ERROR: current transaction is aborted, commands ignored until end of transaction block', '', InternalError('current transaction is aborted, commands ignored until end of transaction block\n',))

2018-07-12 11:30:47,557 [DefaultQuartzScheduler_Worker-10] ERROR com.redhat.rhn.taskomatic.task.RepoSyncTask - Executing a task threw an exception: org.quartz.JobExecutionException
2018-07-12 11:30:47,557 [DefaultQuartzScheduler_Worker-10] ERROR com.redhat.rhn.taskomatic.task.RepoSyncTask - Message: Command '[/usr/bin/spacewalk-repo-sync, --channel, centos6_x86_64, --type, yum]' exited with error code 1
2018-07-12 11:30:47,558 [DefaultQuartzScheduler_Worker-10] ERROR com.redhat.rhn.taskomatic.task.RepoSyncTask - Cause: null
2018-07-12 11:30:47,558 [DefaultQuartzScheduler_Worker-10] ERROR com.redhat.rhn.taskomatic.task.RepoSyncTask - Stack trace:org.quartz.JobExecutionException: Command '[/usr/bin/spacewalk-repo-sync, --channel, centos6_x86_64, --type, yum]' exited with error code 1
at com.redhat.rhn.taskomatic.task.RhnJavaJob.executeExtCmd(RhnJavaJob.java:103)
at com.redhat.rhn.taskomatic.task.RepoSyncTask.execute(RepoSyncTask.java:70)
at com.redhat.rhn.taskomatic.task.RhnJavaJob.execute(RhnJavaJob.java:88)
at com.redhat.rhn.taskomatic.TaskoJob.execute(TaskoJob.java:186)
at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549)

Okay so what do we have here? Obviously it’s something about the database and a duplicate primary key. We also have the repository that caused the error to happen. No hint which entry is the duplicate whatsoever. But we do have the failed command so let’s try that on our own and strace the process and it’s forks:23319 sendto(11, "Q\0\0\0\vCOMMIT\0", 12, MSG_NOSIGNAL, NULL, 0) = 12
23319 poll([{fd=11, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=11, revents=POLLIN}])

23319 recvfrom(11, "C\0\0\0\vCOMMIT\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 18

23319 sendto(5, "Q\0\0\0>select LOOKUP_PACKAGE_NEVRA"..., 63, MSG_NOSIGNAL, NULL, 0) = 63

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0\33\0\1id\0\0\0\0\0\0\0\0\0\6\244\377\377\377\377\377\377\0\0D\0\0\0"..., 16384, 0, NULL, NULL) = 65

23319 sendto(5, "Q\0\0\0?select LOOKUP_PACKAGE_NEVRA"..., 64, MSG_NOSIGNAL, NULL, 0) = 64

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0\33\0\1id\0\0\0\0\0\0\0\0\0\6\244\377\377\377\377\377\377\0\0D\0\0\0"..., 16384, 0, NULL, NULL) = 65

23319 sendto(5, "Q\0\0\0?select LOOKUP_PACKAGE_NEVRA"..., 64, MSG_NOSIGNAL, NULL, 0) = 64

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0\33\0\1id\0\0\0\0\0\0\0\0\0\6\244\377\377\377\377\377\377\0\0D\0\0\0"..., 16384, 0, NULL, NULL) = 65

23319 sendto(5, "Q\0\0\0\210select * from rhnPackage wh"..., 137, MSG_NOSIGNAL, NULL, 0) = 137

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\3#\0\34id\0\0\0\240\4\0\1\0\0\6\244\377\377\377\377\377\377\0\0org_"..., 16384, 0, NULL, NULL) = 1346

23319 sendto(5, "Q\0\0\0\210select * from rhnPackage wh"..., 137, MSG_NOSIGNAL, NULL, 0) = 137

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\3#\0\34id\0\0\0\240\4\0\1\0\0\6\244\377\377\377\377\377\377\0\0org_"..., 16384, 0, NULL, NULL) = 1682

23319 sendto(5, "Q\0\0\0\211select * from rhnPackage wh"..., 138, MSG_NOSIGNAL, NULL, 0) = 138

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\3#\0\34id\0\0\0\240\4\0\1\0\0\6\244\377\377\377\377\377\377\0\0org_"..., 16384, 0, NULL, NULL) = 1478

23319 sendto(5, "Q\0\0\0l\n select channel"..., 109, MSG_NOSIGNAL, NULL, 0) = 109

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0#\0\1channel_id\0\0\0\242\255\0\1\0\0\6\244\377\377\377\377"..., 16384, 0, NULL, NULL) = 56

23319 sendto(5, "Q\0\0\0l\n select channel"..., 109, MSG_NOSIGNAL, NULL, 0) = 109

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0#\0\1channel_id\0\0\0\242\255\0\1\0\0\6\244\377\377\377\377"..., 16384, 0, NULL, NULL) = 56

23319 sendto(5, "Q\0\0\0l\n select channel"..., 109, MSG_NOSIGNAL, NULL, 0) = 109

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0#\0\1channel_id\0\0\0\242\255\0\1\0\0\6\244\377\377\377\377"..., 16384, 0, NULL, NULL) = 56

23319 sendto(5, "Q\0\0\1W\n select pac"..., 344, MSG_NOSIGNAL, NULL, 0) = 344

23319 poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])

23319 recvfrom(5, "T\0\0\0#\0\1package_id\0\0\0\242\255\0\2\0\0\6\244\377\377\377\377"..., 16384, 0, NULL, NULL) = 56

Not very helpful in my opinion as there is no clue on what the package_id is that caused the error. It only confirms what we already know. But when it’s something in correlation to the database we should be able to get more information by logging all the queries done during the sync process. After enabling log_destination = 'stderr' and log_directory = 'pg_log' in postgresql.conf, I restarted the sync and watched the PostgreSQL log closely.
2018-07-12 13:11:09.736 CEST LOG: statement: select LOOKUP_PACKAGE_NAME('centos-release') id from dual
2018-07-12 13:11:09.737 CEST LOG: statement: select LOOKUP_PACKAGE_NAME('python-setuptools') id from dual

2018-07-12 13:11:09.737 CEST LOG: statement: select LOOKUP_PACKAGE_NAME('sysstat') id from dual

2018-07-12 13:11:09.738 CEST LOG: statement: select LOOKUP_EVR(NULL, '9.0.4', '33.el6_9.1') id from dual

2018-07-12 13:11:09.753 CEST LOG: statement: select LOOKUP_EVR(NULL, '6', '10.el6.centos.12.3') id from dual

2018-07-12 13:11:09.767 CEST LOG: statement: select LOOKUP_EVR(NULL, '0.6.10', '4.el6_9') id from dual

2018-07-12 13:11:09.794 CEST LOG: statement: BEGIN

2018-07-12 13:11:09.795 CEST LOG: statement: lock table rhnChecksum in exclusive mode

2018-07-12 13:11:09.797 CEST LOG: statement: select lookup_checksum_fast('sha256', '3cdb75f0d06fe1d39cee6f010a2a487d1b2ba595fa3197bbfac9e9050b2c233f') id from dual

2018-07-12 13:11:09.894 CEST LOG: statement: select lookup_checksum_fast('sha256', '65fa114e7d947143580f98a5feeb652ceb7ebdd8b27fba65ba0b383b250c63d3') id from dual

2018-07-12 13:11:09.922 CEST LOG: statement: select lookup_checksum_fast('sha256', 'e0c9c45557bc787d85417b1daa3799ae61bab899e6475b793cf3488309f94304') id from dual

2018-07-12 13:11:09.954 CEST LOG: statement: COMMIT

2018-07-12 13:11:09.955 CEST LOG: statement: select LOOKUP_PACKAGE_NEVRA(603, 28320, 120) id from dual

2018-07-12 13:11:09.959 CEST LOG: statement: select LOOKUP_PACKAGE_NEVRA(5339, 28321, 100) id from dual

2018-07-12 13:11:09.973 CEST LOG: statement: select LOOKUP_PACKAGE_NEVRA(5913, 28322, 120) id from dual

2018-07-12 13:11:09.974 CEST LOG: statement: select * from rhnPackage where org_id = 1 and name_id = 603 and evr_id = 28320 and package_arch_id = 120 and checksum_id = 10000270

2018-07-12 13:11:09.987 CEST LOG: statement: select * from rhnPackage where org_id = 1 and name_id = 5339 and evr_id = 28321 and package_arch_id = 100 and checksum_id = 9998526

2018-07-12 13:11:09.989 CEST LOG: statement: select * from rhnPackage where org_id = 1 and name_id = 5913 and evr_id = 28322 and package_arch_id = 120 and checksum_id = 10000274

2018-07-12 13:11:09.990 CEST LOG: statement:

select channel_id

from rhnChannelPackage

where package_id = 121940

2018-07-12 13:11:09.991 CEST LOG: statement:

select channel_id

from rhnChannelPackage

where package_id = 121941

2018-07-12 13:11:09.992 CEST LOG: statement:

select channel_id

from rhnChannelPackage

where package_id = 121942

2018-07-12 13:11:09.992 CEST LOG: statement:

select package_id

from rhnChannelPackage cp

join rhnPackage p

on p.id = cp.package_id

join rhnChannel c

on c.id = cp.channel_id

where cp.channel_id = 105

and c.org_id != p.org_id

2018-07-12 13:11:10.206 CEST LOG: statement: insert into rhnChannelPackage (channel_id, package_id) values (105, 121940)

2018-07-12 13:11:10.230 CEST LOG: statement: insert into rhnChannelPackage (channel_id, package_id) values (105, 121941)

2018-07-12 13:11:10.230 CEST LOG: statement: insert into rhnChannelPackage (channel_id, package_id) values (105, 121942)

2018-07-12 13:11:10.231 CEST LOG: statement: SELECT rhn_channel.refresh_newest_package(105, 'server.app.yumreposync', 603)

2018-07-12 13:11:10.406 CEST LOG: statement: SELECT rhn_channel.refresh_newest_package(105, 'server.app.yumreposync', 5339)

2018-07-12 13:11:10.459 CEST ERROR: duplicate key value violates unique constraint "rhn_cnp_cid_nid_uq"

2018-07-12 13:11:10.459 CEST DETAIL: Key (channel_id, name_id, package_arch_id)=(105, 5339, 100) already exists.

2018-07-12 13:11:10.459 CEST CONTEXT: SQL statement "insert into rhnChannelNewestPackage

(channel_id, name_id, evr_id, package_id, package_arch_id)

(select channel_id,

name_id, evr_id,

package_id, package_arch_id

from rhnChannelNewestPackageView

where channel_id = channel_id_in

and (package_name_id_in is null

or name_id = package_name_id_in)

)"

PL/pgSQL function rhn_channel.refresh_newest_package(numeric,character varying,numeric) line 9 at SQL statement

2018-07-12 13:11:10.459 CEST STATEMENT: SELECT rhn_channel.refresh_newest_package(105, 'server.app.yumreposync', 5339)

2018-07-12 13:11:10.462 CEST LOG: statement:

select k1.description as ca_cert_name, k1.key as ca_cert, k1.org_id as ca_cert_org,

k2.description as client_cert_name, k2.key as client_cert, k2.org_id as client_cert_org,

k3.description as client_key_name, k3.key as client_key, k3.org_id as client_key_org

from rhncontentsource cs inner join

rhncontentsourcessl csssl on cs.id = csssl.content_source_id inner join

rhncryptokey k1 on csssl.ssl_ca_cert_id = k1.id left outer join

rhncryptokey k2 on csssl.ssl_client_cert_id = k2.id left outer join

rhncryptokey k3 on csssl.ssl_client_key_id = k3.id

where cs.id = 507

2018-07-12 13:11:10.462 CEST ERROR: current transaction is aborted, commands ignored until end of transaction block

2018-07-12 13:11:10.462 CEST STATEMENT:

select k1.description as ca_cert_name, k1.key as ca_cert, k1.org_id as ca_cert_org,

k2.description as client_cert_name, k2.key as client_cert, k2.org_id as client_cert_org,

k3.description as client_key_name, k3.key as client_key, k3.org_id as client_key_org

from rhncontentsource cs inner join

rhncontentsourcessl csssl on cs.id = csssl.content_source_id inner join

rhncryptokey k1 on csssl.ssl_ca_cert_id = k1.id left outer join

rhncryptokey k2 on csssl.ssl_client_cert_id = k2.id left outer join

rhncryptokey k3 on csssl.ssl_client_key_id = k3.id


where cs.id = 507

There we have the package_ids that have to be in any way responsible for the failed sync. Let’s do a quick search via the GUI to find out more about them. After looking them up one by one I found out that all three of them where still in the package queue and not associated with a channel yet. You can see that in the software package manager.

Orphaned packages

So what now? I know that these packages remain in the queue because the import fails but the real cause of the error seems to be something that’s already in the database which has some attribute with exact the same value as one of these three packages. Let’s google that error message and see if someone had the same issue in the past.
Seems like this happend once in 2016 because of a duplicate package published with Red Hat. Let’s see if one of these packages already exists in the database. Bingo! The sysstat and python-setuptools package have already been published some month prior but with a faulty name schema. Like in 2016 the package names didn’t contain a dot between the package version and the OS release version. In theory simply deleting the faulty package should solve the problem but let’s see…

Delete the duplicate package

Okay and now let’s try to rerun the channel synchronisation and see if it runs without errors.
13:51:02 Sync of channel completed in 0:04:30.
13:51:02 Total time: 0:04:30

Perfect 🙂

I2P with the Tor browser bundle

Based on the The Tin Hat Turotial on how to use the Tor browser with I2P, I tried to import the FoxyProxy configuration file to my FoxyProxy. Unfortunately the format FoxyProxy uses to export and import settings seems to has changed so that the import failed. Because of that I set up the needed proxies and filters manually and exported my ruleset. Everybody who wants to use the Tor browser for both Tor and I2P can download my exported config and import it or set up the rules manually based on the config file.

Yaesu FT-2DE

I want to share my experiences with the Yaesu FT-2DE with you, especially because there are not many reviews on this device at the given time. As a disclaimer: this is my first high price ham radio device! Therefore I am unable to compare it to other high price sellers and cannot rate the device compared to others in the points of build quality and stuff like that. Also I do not own a DMR or D-Star device and can only reflect my gained experiences with C4FM.

I bought the device second hand from a OM I was referred to. He was unable to use C4FM frequently because there is no repeater in his living area. To be honest in and around Berlin the density of repeaters capable of C4FM is not the best as you can see on the repeater map by DB0WHR. Fortunately I can reach DB0BLO from my QTH.

Lets get going:
First impression
(tbd)

Quick Info: VMware Workstation network not working

Lately I moved my VMware Workstation to another machine and since then neither the vmnet NICs nor any of the VMware network services was working.
With vmware-network –status the status of the virtual NICs and netservices can be checked. I got
Bridge networking on vmnet0 is not running
DHCP service on vmnet1 is not running
Hostonly virtual adapter on vmnet1 is disabled
DHCP service on vmnet8 is not running
NAT service on vmnet8 is not running
Hostonly virtual adapter on vmnet8 is disabled
Some/All of the configured services are not running

as respons. I tried to fix that by  vmware-network –start but got Failed to start some/all services back so I started investigating. The answer to that was a missing kernel mod calles vmnet. A quick modprobe vmnet and again a restart of the service fixed the issue.

Quick Info: Pushbullet end-to-end encryption not working on Firefox

About a week ago I started using Pushbullet on my phone again. We all know that WhatsApp web sucks balls but I’m far to lazy to get the phone out of my pocket everytime someone sends me a WhatsApp message. Pushbullet then sends the messages to my always running Firefox where I can read and respond to them. The integrated end-to-end encryption feature in Pushbullet caught my attention so I set up an encryption password on my phone and in my browser but the Firefox AddOn wasn’t able to encrypt any of the forwarded messages. Instead it always showed me a prompt asking for the encryption password.
The cause of that issue was the Fanboy Social Blocking List in AdBlock Plus which blocked the Pushbullet AddOn page on which you set up the encryption password. After disabling ABP for the AddOn Page everything was working perfectly.

Quick Info: No access to Veracrypt encrypted volume after mounting as non-root

I recently switched over to Debian on my desktop computer (thx @Hypfer for convincing me to do this). One of the first issues I ran into was the fact that after I mounted my encrypted external harddrive it was only readable for the root user. The cause of this is that I start Veracrypt via gksudo because otherwise I was not able to mount my drives since my main user is not in the sudoers list.
The solution to that is to create an exception for the user that you want to mount the volume with:%[group of your user] ALL=(root) NOPASSWD:/path/to/veracrypt
After that all users in this group are able to mount volumes with Veracrypt and access the content.

Quick Info: Debian stuck at boot due to IPv6

Lately I bought a couple HDDs to finish my home made NAS running OpenMediaVault Debian. I personally think that IPv6 should be supported by any means, so I activated it right after finishing the installation process and everything was working fine. I shut down the system during the night hours because there was no reason to leave it on because I had not yet copied any data onto the NAS.
Next day the system got stuck at bootup! At first I thought something messed up the resolv.conf because the bootup process was throwing a couple errors that indicated something like that but in the end it was the NIC waiting for an IPv6 lease from the DHCP server runnig on my fritzbox (don’t judge me, if I could this thing would take a visit to the trash can asap). The DHCP was somehow misconfigured so that Debian was waiting endlessly for an address.
I fixed it by enabling IA_PD and IA_NA in the fritzbox GUI and voilà Debian finished booting right away.