Project

General

Profile

Actions
Copy link

Bug #69473

closed

lua tests against rgw: test_access_log failure

Added by Casey Bodley about 1 year ago. Updated 5 months ago.

Status:
Resolved
Priority:
Urgent
Assignee:
Yuval Lifshitz
Target version:
-
% Done:

0%

Source:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
61387
Tags (freeform):
lua
Merge Commit:
f900942d7ac99921edbaf89ad5aa9bc0bf605c62
Fixed In:
v19.3.0-6940-gf900942d7a
Released In:
v20.2.0~1329
Upkeep Timestamp:
2025-11-01T01:29:36+00:00

Description

the culprit appears to be:

$ radosgw-admin script-package add --package=lua-cjson --allow-compilation
ERROR: failed to add Lua package:  lua-cjson .error: -10

from https://qa-proxy.ceph.com/teuthology/mbenjamin-2025-01-09_16:41:14-rgw-wip-object-attributes-distro-default-smithi/8069515/teuthology.log
:=================================== FAILURES ===================================
_______________________________ test_access_log ________________________________

    @pytest.mark.example_test
    def test_access_log():
        bucket_name = gen_bucket_name()
        socket_path = '/tmp/'+bucket_name

        script = '''
    if Request.RGWOp == "get_obj" then
        local json = require("cjson")
        local socket = require("socket")
        local unix = require("socket.unix")
        local s = unix()
        E = {{}}

        msg = {{bucket = (Request.Bucket or (Request.CopyFrom or E).Bucket).Name,
            object = Request.Object.Name,
            time = Request.Time,
            operation = Request.RGWOp,
            http_status = Request.Response.HTTPStatusCode,
            error_code = Request.Response.HTTPStatus,
            object_size = Request.Object.Size,
            trans_id = Request.TransactionId}}
        assert(s:connect("{}"))
        s:send(json.encode(msg).."\\n")
        s:close()
    end
    '''.format(socket_path)

        result = admin(['script-package', 'add', '--package=lua-cjson', '--allow-compilation'])
>       assert result[1] ==  0
E       assert 10 == 0

test_lua.py:435: AssertionError
----------------------------- Captured stderr call -----------------------------
ignoring --setuser ceph since I am not root
ignoring --setgroup ceph since I am not root
2025-01-09T17:17:11.100+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.100+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.100+0000 7f07e9076a80 20 realm
2025-01-09T17:17:11.100+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.100+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.100+0000 7f07e9076a80  4 RGWPeriod::init failed to init realm  id  : (2) No such file or directory
2025-01-09T17:17:11.100+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.104+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.104+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.104+0000 7f07e9076a80 20 rados_obj.operate() r=0 bl.length=46
2025-01-09T17:17:11.104+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.104+0000 7f07e9076a80 20 rados_obj.operate() r=0 bl.length=1123
2025-01-09T17:17:11.104+0000 7f07e9076a80 20 searching for the correct realm
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 RGWRados::pool_iterate: got default.zonegroup.
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 RGWRados::pool_iterate: got zone_info.02b59c37-15f7-42af-87c2-6e68898df81b
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 RGWRados::pool_iterate: got zonegroup_info.b5eff4ef-fc80-4b73-ad7a-c7ec793fabbb
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 RGWRados::pool_iterate: got default.zone.
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 RGWRados::pool_iterate: got zone_names.default
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 RGWRados::pool_iterate: got zonegroups_names.default
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados_obj.operate() r=0 bl.length=46
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados_obj.operate() r=0 bl.length=470
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 zone default found
2025-01-09T17:17:11.124+0000 7f07e9076a80  4 Realm:                          ()
2025-01-09T17:17:11.124+0000 7f07e9076a80  4 ZoneGroup: default              (b5eff4ef-fc80-4b73-ad7a-c7ec793fabbb)
2025-01-09T17:17:11.124+0000 7f07e9076a80  4 Zone:      default              (02b59c37-15f7-42af-87c2-6e68898df81b)
2025-01-09T17:17:11.124+0000 7f07e9076a80 10 cannot find current period zonegroup using local zonegroup configuration
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 zonegroup default
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados->read ofs=0 len=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 rados_obj.operate() r=-2 bl.length=0
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 started sync module instance, tier type =
2025-01-09T17:17:11.124+0000 7f07e9076a80 20 started zone id=02b59c37-15f7-42af-87c2-6e68898df81b (name=default) with tier type =
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=0
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=1
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=2
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=3
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=4
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=5
2025-01-09T17:17:11.140+0000 7f07e9076a80 20 add_watcher() i=6
2025-01-09T17:17:11.144+0000 7f07e9076a80 20 add_watcher() i=7
2025-01-09T17:17:11.144+0000 7f07e9076a80  2 all 8 watchers are set, enabling cache
2025-01-09T17:17:11.144+0000 7f0699fe3640  2 rgw data changes log: RGWDataChangesLog::ChangesRenewThread: start
2025-01-09T17:17:11.144+0000 7f07e9076a80 20 rgw_check_secure_mon_conn(): auth registy supported: methods=[2] modes=[2,1]
2025-01-09T17:17:11.144+0000 7f07e9076a80 20 rgw_check_secure_mon_conn(): mode 1 is insecure
2025-01-09T17:17:11.144+0000 7f07e9076a80  5 note: GC not initialized
2025-01-09T17:17:11.144+0000 7f0698fe1640 20 reqs_thread_entry: start
2025-01-09T17:17:11.144+0000 7f07e9076a80 20 init_complete bucket index max shards: 11
2025-01-09T17:17:11.144+0000 7f07e9076a80 20 Filter name: none
2025-01-09T17:17:11.144+0000 7f06127fc640 20 reqs_thread_entry: start
ERROR: failed to add Lua package:  lua-cjson .error: -10
2025-01-09T17:17:11.148+0000 7f0699fe3640  2 rgw data changes log: RGWDataChangesLog::ChangesRenewThread: start
2025-01-09T17:17:11.152+0000 7f07e9076a80 20 remove_watcher() i=0
2025-01-09T17:17:11.152+0000 7f07e9076a80  2 removed watcher, disabling cache
2025-01-09T17:17:11.152+0000 7f07e9076a80 20 remove_watcher() i=1
2025-01-09T17:17:11.156+0000 7f07e9076a80 20 remove_watcher() i=2
2025-01-09T17:17:11.156+0000 7f07e9076a80 20 remove_watcher() i=3
2025-01-09T17:17:11.156+0000 7f07e9076a80 20 remove_watcher() i=4
2025-01-09T17:17:11.160+0000 7f07e9076a80 20 remove_watcher() i=5
2025-01-09T17:17:11.160+0000 7f07e9076a80 20 remove_watcher() i=6
2025-01-09T17:17:11.160+0000 7f07e9076a80 20 remove_watcher() i=7
=========================== short test summary info ============================
FAILED test_lua.py::test_access_log - assert 10 == 0
========================= 1 failed, 5 passed in 49.96s =========================

Actions
Copy link
 #1

Updated by Yuval Lifshitz about 1 year ago

the error code ECHILD mean that luarocks is not installed on the test machine

Actions
Copy link
 #2

Updated by Yuval Lifshitz about 1 year ago

looks like that for ubuntu luarocks is under "suggeted packages", since it is not a hard dependency for ceph.
change was done here: https://github.com/ceph/ceph/pull/60666
one option is to revert the above change, or we can install luarocks explicitly for the lua test suite.

Actions
Copy link
 #3

Updated by Yuval Lifshitz about 1 year ago

installing luarocks as part of the test does not seem to fix the entire problem. from the test log:
http://qa-proxy.ceph.com/teuthology/yuvalif-2025-01-15_08:24:50-rgw:lua-wip-yuval-69473-distro-default-smithi/8078358/teuthology.log
it looks like lua5.1 is installed, instead of 5.3:

2025-01-15T08:45:13.415 INFO:teuthology.orchestra.run.smithi083.stdout:The following additional packages will be installed:
2025-01-15T08:45:13.416 INFO:teuthology.orchestra.run.smithi083.stdout:  liblua5.1-0 liblua5.1-0-dev libreadline-dev lua-any lua-sec lua-socket
2025-01-15T08:45:13.416 INFO:teuthology.orchestra.run.smithi083.stdout:  lua5.1 pkg-config unzip zip

whis is strange, since the code has `liblua5.3`: https://github.com/ceph/ceph/blob/main/debian/control#L999

later on in the test when we try to use luarocks to install the luajson package (of version 5.3) we get a warning:

2025-01-15T08:49:11.051+0000 7f7cd3fad640 20 rgw lua package reloader: Lua CMD: /usr/bin/luarocks install --no-doc --lua-version 5.3 --tree /tmp/rgw_luarocks/client.0/ZsKuZV --deps-mode one lua-cjson
Warning: Lua 5.3 interpreter not found at /usr
Modules may not install with the correct configurations. You may want to configure the path prefix to your build of Lua 5.3 using

and weh we try to use it, we get an error:
2025-01-15T08:49:13.839+0000 7f7d10025640  1 req 15932861218285072941 0.011999628s Lua ERROR: [string "..."]:3: module 'cjson' not found:
   no field package.preload['cjson']
   no file '/tmp/rgw_luarocks/client.0/ZsKuZV/share/lua/5.3/cjson.lua'
   no file '/tmp/rgw_luarocks/client.0/ZsKuZV/lib/lua/5.3/cjson.so'
   no file '/tmp/rgw_luarocks/client.0/ZsKuZV/lib64/lua/5.3/cjson.so'

Actions
Copy link
 #4

Updated by Yuval Lifshitz about 1 year ago

  • Status changed from New to Fix Under Review
  • Pull request ID set to 61387
Actions
Copy link
 #5

Updated by J. Eric Ivancich about 1 year ago

  • Status changed from Fix Under Review to Resolved
Actions
Copy link
 #6

Updated by Upkeep Bot 9 months ago

  • Merge Commit set to f900942d7ac99921edbaf89ad5aa9bc0bf605c62
  • Fixed In set to v19.3.0-6940-gf900942d7ac
  • Upkeep Timestamp set to 2025-07-10T00:36:02+00:00
Actions
Copy link
 #7

Updated by Upkeep Bot 8 months ago

  • Fixed In changed from v19.3.0-6940-gf900942d7ac to v19.3.0-6940-gf900942d7a
  • Upkeep Timestamp changed from 2025-07-10T00:36:02+00:00 to 2025-07-14T19:37:44+00:00
Actions
Copy link
 #8

Updated by Upkeep Bot 5 months ago

  • Released In set to v20.2.0~1329
  • Upkeep Timestamp changed from 2025-07-14T19:37:44+00:00 to 2025-11-01T01:29:36+00:00
Actions
Copy link

Also available in: Atom PDF