XMLR-RPC debug info
koji --debug --debug-xmlrpc -c /home/mfilip/.virtualenvs/koji-biweekly/koji/clients/default/config call createUser user-ěščřž 2020-03-26 14:00:39,413 [DEBUG] koji: Opening new requests session 2020-03-26 14:00:39,414 [DEBUG] koji: Opening new requests session 2020-03-26 14:00:39,414 [DEBUG] koji: url: https://10.0.104.197/kojihub/ssllogin 2020-03-26 14:00:39,414 [DEBUG] koji: headers: {'User-Agent': 'koji/1', 'Content-Type': 'text/xml', 'Content-Length': '140'} 2020-03-26 14:00:39,414 [DEBUG] koji: data: '0x3c3f786d6c2076657273696f6e3d27312e30273f3e0a3c6d6574686f6443616c6c3e0a3c6d6574686f644e616d653e73736c4c6f67696e3c2f6d6574686f644e616d653e0a3c706172616d733e0a3c706172616d3e0a3c76616c75653e3c6e696c2f3e3c2f76616c75653e3c2f706172616d3e0a3c2f706172616d733e0a3c2f6d6574686f6443616c6c3e0a' 2020-03-26 14:00:39,414 [DEBUG] koji: stream: True 2020-03-26 14:00:39,414 [DEBUG] koji: verify: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/serverca.crt' 2020-03-26 14:00:39,414 [DEBUG] koji: cert: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/client.crt' 2020-03-26 14:00:39,414 [DEBUG] koji: timeout: 60 2020-03-26 14:00:40,299 [DEBUG] koji: body: b"<?xml version='1.0'?>\n<methodResponse>\n<params>\n<param>\n<value><struct>\n<member>\n<name>session-id</name>\n<value><int>16</int></value>\n</member>\n<member>\n<name>session-key</name>\n<value><string>2-fnqDKVvnVwUnPKRHp6W</string></value>\n</member>\n</struct></value>\n</param>\n</params>\n</methodResponse>\n" 2020-03-26 14:00:40,300 [DEBUG] koji: url: https://10.0.104.197/kojihub?session-id=16&session-key=2-fnqDKVvnVwUnPKRHp6W&callnum=0 2020-03-26 14:00:40,300 [DEBUG] koji: headers: {'User-Agent': 'koji/1', 'Content-Type': 'text/xml', 'Content-Length': '107'} 2020-03-26 14:00:40,300 [DEBUG] koji: data: '0x3c3f786d6c2076657273696f6e3d27312e30273f3e0a3c6d6574686f6443616c6c3e0a3c6d6574686f644e616d653e67657441504956657273696f6e3c2f6d6574686f644e616d653e0a3c706172616d733e0a3c2f706172616d733e0a3c2f6d6574686f6443616c6c3e0a' 2020-03-26 14:00:40,300 [DEBUG] koji: stream: True 2020-03-26 14:00:40,300 [DEBUG] koji: verify: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/serverca.crt' 2020-03-26 14:00:40,300 [DEBUG] koji: cert: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/client.crt' 2020-03-26 14:00:40,301 [DEBUG] koji: timeout: 43200 2020-03-26 14:00:40,452 [DEBUG] koji: body: b"<?xml version='1.0'?>\n<methodResponse>\n<params>\n<param>\n<value><int>1</int></value>\n</param>\n</params>\n</methodResponse>\n" successfully connected to hub 2020-03-26 14:00:40,453 [DEBUG] koji: url: https://10.0.104.197/kojihub?session-id=16&session-key=2-fnqDKVvnVwUnPKRHp6W&callnum=1 2020-03-26 14:00:40,453 [DEBUG] koji: headers: {'User-Agent': 'koji/1', 'Content-Type': 'text/xml', 'Content-Length': '169'} 2020-03-26 14:00:40,453 [DEBUG] koji: data: '0x3c3f786d6c2076657273696f6e3d27312e30273f3e0a3c6d6574686f6443616c6c3e0a3c6d6574686f644e616d653e637265617465557365723c2f6d6574686f644e616d653e0a3c706172616d733e0a3c706172616d3e0a3c76616c75653e3c737472696e673e757365722dc49bc5a1c48dc599c5be3c2f737472696e673e3c2f76616c75653e0a3c2f706172616d3e0a3c2f706172616d733e0a3c2f6d6574686f6443616c6c3e0a' 2020-03-26 14:00:40,453 [DEBUG] koji: stream: True 2020-03-26 14:00:40,453 [DEBUG] koji: verify: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/serverca.crt' 2020-03-26 14:00:40,454 [DEBUG] koji: cert: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/client.crt' 2020-03-26 14:00:40,454 [DEBUG] koji: timeout: 43200 2020-03-26 14:00:40,608 [DEBUG] koji: body: b"<?xml version='1.0'?>\n<methodResponse>\n<fault>\n<value><struct>\n<member>\n<name>faultCode</name>\n<value><int>1</int></value>\n</member>\n<member>\n<name>faultString</name>\n<value><string><class 'UnicodeEncodeError'>: 'ascii' codec can't encode characters in position 5-9: ordinal not in range(128)</string></value>\n</member>\n</struct></value>\n</fault>\n</methodResponse>\n" Traceback (most recent call last): File "/home/mfilip/.virtualenvs/koji-biweekly/bin/koji", line 335, in <module> rv = locals()[command].__call__(options, session, args) File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji_cli/commands.py", line 922, in handle_call response = getattr(session, name).__call__(*non_kw, **kw) File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji/__init__.py", line 2263, in __call__ return self.__func(self.__name, args, opts) File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji/__init__.py", line 2804, in _callMethod raise err File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji/__init__.py", line 2785, in _callMethod return self._sendCall(handler, headers, request) File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji/__init__.py", line 2703, in _sendCall return self._sendOneCall(handler, headers, request) File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji/__init__.py", line 2749, in _sendOneCall ret = self._read_xmlrpc_response(r) File "/home/mfilip/.virtualenvs/koji-biweekly/lib/python3.7/site-packages/koji/__init__.py", line 2761, in _read_xmlrpc_response result = u.close() File "/usr/lib64/python3.7/xmlrpc/client.py", line 656, in close raise Fault(**self._stack[0]) xmlrpc.client.Fault: <Fault 1: "<class 'UnicodeEncodeError'>: 'ascii' codec can't encode characters in position 5-9: ordinal not in range(128)"> 2020-03-26 14:00:40,646 [DEBUG] koji: url: https://10.0.104.197/kojihub?session-id=16&session-key=2-fnqDKVvnVwUnPKRHp6W&callnum=2 2020-03-26 14:00:40,646 [DEBUG] koji: headers: {'User-Agent': 'koji/1', 'Content-Type': 'text/xml', 'Content-Length': '100'} 2020-03-26 14:00:40,646 [DEBUG] koji: data: '0x3c3f786d6c2076657273696f6e3d27312e30273f3e0a3c6d6574686f6443616c6c3e0a3c6d6574686f644e616d653e6c6f676f75743c2f6d6574686f644e616d653e0a3c706172616d733e0a3c2f706172616d733e0a3c2f6d6574686f6443616c6c3e0a' 2020-03-26 14:00:40,646 [DEBUG] koji: stream: True 2020-03-26 14:00:40,647 [DEBUG] koji: verify: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/serverca.crt' 2020-03-26 14:00:40,647 [DEBUG] koji: cert: '/home/mfilip/.virtualenvs/koji-biweekly/koji/clients/kojiadmin/client.crt' 2020-03-26 14:00:40,647 [DEBUG] koji: timeout: 43200
hub log:
[Thu Mar 26 13:50:06.450995 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,450 [DEBUG] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.xmlrpc: Opts: {} [Thu Mar 26 13:50:06.451323 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,451 [DEBUG] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: b'SELECT name\\n FROM user_perms JOIN permissions ON perm_id = permissions.id\\n WHERE active = TRUE AND user_id=2' [Thu Mar 26 13:50:06.452104 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,452 [DEBUG] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: Execute operation completed in 0.0006 seconds [Thu Mar 26 13:50:06.452286 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,452 [DEBUG] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: fetchall operation completed in 0.0000 seconds [Thu Mar 26 13:50:06.453523 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,452 [ERROR] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: Unable to quote query: [Thu Mar 26 13:50:06.453618 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.453676 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] SELECT id, name, status, usertype [Thu Mar 26 13:50:06.453732 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] FROM users [Thu Mar 26 13:50:06.453772 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] LEFT JOIN user_krb_principals ON users.id = user_krb_principals.user_id [Thu Mar 26 13:50:06.453831 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] WHERE (krb_principal = %(info)s OR name = %(info)s) [Thu Mar 26 13:50:06.453889 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.453953 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.454004 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.454079 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.454130 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.454180 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] Parameters: {'info': 'user-\xc4\x9b\xc5\xa1\xc4\x8d\xc5\x99\xc5\xbe'} [Thu Mar 26 13:50:06.454231 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] Traceback (most recent call last): [Thu Mar 26 13:50:06.454281 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/lib/python3.7/site-packages/koji/db.py", line 111, in quote [Thu Mar 26 13:50:06.454350 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] return quote(operation, parameters) [Thu Mar 26 13:50:06.454404 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] UnicodeEncodeError: 'ascii' codec can't encode characters in position 5-9: ordinal not in range(128) [Thu Mar 26 13:50:06.454570 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,454 [DEBUG] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: INVALID QUERY [Thu Mar 26 13:50:06.454880 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,454 [ERROR] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: Unable to quote query: [Thu Mar 26 13:50:06.454956 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455011 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] SELECT id, name, status, usertype [Thu Mar 26 13:50:06.455074 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] FROM users [Thu Mar 26 13:50:06.455137 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] LEFT JOIN user_krb_principals ON users.id = user_krb_principals.user_id [Thu Mar 26 13:50:06.455190 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] WHERE (krb_principal = %(info)s OR name = %(info)s) [Thu Mar 26 13:50:06.455224 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455257 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455289 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455322 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455354 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455387 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] Parameters: {'info': 'user-\xc4\x9b\xc5\xa1\xc4\x8d\xc5\x99\xc5\xbe'} [Thu Mar 26 13:50:06.455420 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] Traceback (most recent call last): [Thu Mar 26 13:50:06.455453 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/lib/python3.7/site-packages/koji/db.py", line 142, in execute [Thu Mar 26 13:50:06.455498 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] ret = self.cursor.execute(operation, parameters) [Thu Mar 26 13:50:06.455539 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] UnicodeEncodeError: 'ascii' codec can't encode characters in position 5-9: ordinal not in range(128) [Thu Mar 26 13:50:06.455573 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455606 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] During handling of the above exception, another exception occurred: [Thu Mar 26 13:50:06.455639 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.455671 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] Traceback (most recent call last): [Thu Mar 26 13:50:06.455704 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/lib/python3.7/site-packages/koji/db.py", line 111, in quote [Thu Mar 26 13:50:06.455736 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] return quote(operation, parameters) [Thu Mar 26 13:50:06.455769 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] UnicodeEncodeError: 'ascii' codec can't encode characters in position 5-9: ordinal not in range(128) [Thu Mar 26 13:50:06.455910 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,455 [ERROR] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.db: Query failed. Query was: INVALID QUERY [Thu Mar 26 13:50:06.457001 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,456 [WARNING] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.xmlrpc: Traceback (most recent call last): [Thu Mar 26 13:50:06.457078 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojixmlrpc.py", line 238, in _wrap_handler [Thu Mar 26 13:50:06.457115 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] response = handler(environ) [Thu Mar 26 13:50:06.457149 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojixmlrpc.py", line 281, in handle_rpc [Thu Mar 26 13:50:06.457182 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] return self._dispatch(method, params) [Thu Mar 26 13:50:06.457215 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojixmlrpc.py", line 318, in _dispatch [Thu Mar 26 13:50:06.457247 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] ret = koji.util.call_with_argcheck(func, params, opts) [Thu Mar 26 13:50:06.457280 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/lib/python3.7/site-packages/koji/util.py", line 258, in call_with_argcheck [Thu Mar 26 13:50:06.457314 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] return func(*args, **kwargs) [Thu Mar 26 13:50:06.457346 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojihub.py", line 11678, in createUser [Thu Mar 26 13:50:06.457379 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] if get_user(username): [Thu Mar 26 13:50:06.457412 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojihub.py", line 3889, in get_user [Thu Mar 26 13:50:06.457445 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] user = query.executeOne() [Thu Mar 26 13:50:06.457512 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojihub.py", line 9148, in executeOne [Thu Mar 26 13:50:06.457549 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] results = self.execute() [Thu Mar 26 13:50:06.457582 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojihub.py", line 9097, in execute [Thu Mar 26 13:50:06.457615 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] data = _multiRow(query, self.values, (self.aliases or self.columns)) [Thu Mar 26 13:50:06.457648 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojihub.py", line 5081, in _multiRow [Thu Mar 26 13:50:06.457681 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] return [dict(zip(fields, row)) for row in _fetchMulti(query, values)] [Thu Mar 26 13:50:06.457714 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/share/koji-hub/kojihub.py", line 5051, in _fetchMulti [Thu Mar 26 13:50:06.457747 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] c.execute(query, values) [Thu Mar 26 13:50:06.457780 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] File "/usr/lib/python3.7/site-packages/koji/db.py", line 142, in execute [Thu Mar 26 13:50:06.457813 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] ret = self.cursor.execute(operation, parameters) [Thu Mar 26 13:50:06.457845 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] UnicodeEncodeError: 'ascii' codec can't encode characters in position 5-9: ordinal not in range(128) [Thu Mar 26 13:50:06.457878 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] [Thu Mar 26 13:50:06.458523 2020] [wsgi:error] [pid 24102] [client 10.40.194.1:54002] 2020-03-26 13:50:06,458 [DEBUG] m=createUser u=kojiadmin p=24102 r=10.40.194.1:54002 koji.xmlrpc: Returning 371 bytes after 0.030031 seconds [Thu Mar 26 13:50:09.538776 2020] [wsgi:error] [pid 24019] [client 10.0.105.171:33878] 2020-03-26 13:50:09,538 [DEBUG] m=listBuildroots u=None p=24019 r=10.0.105.171:33878 koji.db: b"\\n SELECT authtype,callnum,exclusive,expired,master,start_time,EXTRACT(EPOCH FROM start_time),update_time,EXTRACT(EPOCH FROM update_time),user_id FROM sessions\\n WHERE id = 12\\n AND key = E'6-ChbBqcnDG2TkiAnORXf'\\n AND hostip = E'10.0.105.171'\\n FOR UPDATE\\n "
Metadata Update from @julian8628: - Custom field Size adjusted to None
Metadata Update from @tkopecek: - Issue set to the milestone: 1.21
Metadata Update from @tkopecek: - Issue tagged with: bug
Part of the problem is, that we end with "random" client encoding, so it works in some deployments, while not in others. There is a server-side solution #2105 , but it will not fix the problem for new client connecting to old hub. I'm thinking of reverting #2040 (which will hide this bug again) and reenabling it version later?
@mikem @julian8628 ?
Found the root cause is client_encoding is set to sql_ascii in brew QE's postgersql DB's config file(it is the same as the DB where I reproduced this problem). So it doesn't care about the actual "Encoding" of the koji database. Not related to #2040 AFAIK.
client_encoding
sql_ascii
I think PR #2015 is still valuable, or we should tell this in our bootstrap doc.
@julian8628 So, it is not a regression? It is doing the same with 1.20?
No, it's not. it's only related to the client_encoding setting of postgresql server.
It's unclear to me just how much unicode is sane in a name field. Accented characters seem ok, but obscure graphic characters seem questionable. There is potential for user confusion. with similar looking characters. I've opened #2117 for discussion of the larger issue.
PR: https://pagure.io/koji/pull-request/2105
Metadata Update from @jcupova: - Issue tagged with: testing-ready
Commit cb3e5308 fixes this issue
Commit f2a57c84 relates to this ticket
Metadata Update from @mfilip: - Issue tagged with: testing-done
This issue has been migrated to Fedora Forge: https://forge.fedoraproject.org/koji/koji/issues/2104
Please continue any further discussion there.