Skip to content

Conversation

irfanHaslanded
Copy link
Contributor

Using strlen() on large strings (large imported data) is extremely inefficient. The ly_time_str2time() only needs to check that the string is at least as long as a valid time value.

However, the full value string can be very long (even > 10MB), and evaluating strlen() for every time value results in poor performance.

Using strlen() on large strings (large imported data) is extremely
inefficient. The ly_time_str2time() only needs to check that the string
is at least as long as a valid time value.

However, the full value string can be very long (even > 10MB),
and evaluating strlen() for every time value results in poor performance.
Copy link
Member

@michalvasko michalvasko left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No problem but I am not sure why would you pass this function strings that "are very long".

@michalvasko michalvasko merged commit 14a0c08 into CESNET:devel Feb 14, 2025
10 of 11 checks passed
@irfanHaslanded
Copy link
Contributor Author

irfanHaslanded commented Feb 14, 2025

No problem but I am not sure why would you pass this function strings that "are very long".

I don't think we are calling this function directly, but sysrepo is calling this internally, while parsing stored JSON data.

This is being called from lyplg_type_store_date_and_time()

@michalvasko
Copy link
Member

Could you please point me to such a use-case? I could not reproduce it in sysrepo tests.

@irfanHaslanded irfanHaslanded deleted the irfan/opt-ly_time_str2time branch February 17, 2025 09:38
@irfanHaslanded
Copy link
Contributor Author

I think I can add a minimal test to sysrepo that exposes this. Will do.

@irfanHaslanded
Copy link
Contributor Author

It's a bit problematic for valgrind because it takes up too much time, but here is the repro

[ RUN      ] test_date_time_scale

Breakpoint 1, sr_get_data (session=0x555555646d80, xpath=0x5555555625c7 "/ietf-interfaces:interfaces", max_depth=0, timeout_ms=1, opts=16, data=0x7fffffffd140)
    at /home/irfan/opensource/sysrepo/src/sysrepo.c:3143
3143        sr_error_info_t *err_info = NULL;
Breakpoint 2 at 0x7ffff7ddcb60: file /home/irfan/intake/libyang/src/tree_data_common.c, line 1666.
Continuing.

Breakpoint 2, ly_time_str2time (
    value=value@entry=0x7ffff78b7096 "2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth2\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"et"..., time=time@entry=0x7fffffffc110, fractions_s=fractions_s@entry=0x7fffffffc118)
    at /home/irfan/intake/libyang/src/tree_data_common.c:1666
1666        struct tm tm = {0};
(gdb) n
1673        LY_CHECK_ARG_RET(NULL, value, strlen(value) > 17, time, LY_EINVAL);
(gdb)
1675        tm.tm_year = atoi(&value[0]) - 1900;
(gdb) call (int)strlen(value)
$1 = 1668841
(gdb)

Code here sysrepo/sysrepo#3549

/* TEST */
static void
test_date_time_scale(void **state)
{
    struct state *st = (struct state *)*state;
    int ret, i;
    sr_data_t *data;
    char xpath[128] = "";

    /* switch to operational DS */
    ret = sr_session_switch_ds(st->sess, SR_DS_OPERATIONAL);
    assert_int_equal(ret, SR_ERR_OK);

    for (i = 0; i < 20000; i++) {
        snprintf(xpath, sizeof(xpath), "/ietf-interfaces:interfaces-state/interface[name='eth%d']/statistics/discontinuity-time", i);
        ret = sr_set_item_str(st->sess, xpath, "2019-10-29T09:43:12-00:00", NULL, 0);
        assert_int_equal(ret, SR_ERR_OK);
    }

    ret = sr_apply_changes(st->sess, 0);
    assert_int_equal(ret, SR_ERR_OK);

    /* a short timeout value of 1 ms */
    ret = sr_get_data(st->sess, "/ietf-interfaces:interfaces", 0, 1, SR_OPER_WITH_ORIGIN, &data);
    assert_int_equal(ret, SR_ERR_OK);
    sr_release_data(data);
}

@irfanHaslanded
Copy link
Contributor Author

#1  ly_time_str2time (
    value=value@entry=0x7ffff78b7096 "2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth2\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"et"..., time=time@entry=0x7fffffffc110, fractions_s=fractions_s@entry=0x7fffffffc118)
    at /home/irfan/intake/libyang/src/tree_data_common.c:1675
#2  0x00007ffff7e8f4e8 in lyplg_type_store_date_and_time (ctx=0x5555555ab3b0, type=<optimized out>, value=0x7ffff78b7096, value_len=25, options=<optimized out>,
    format=LY_VALUE_JSON, UNUSED_prefix_data=0x0, hints=17, UNUSED_ctx_node=0x5555556c5490, storage=0x7fffffffc100, UNUSED_unres=0x0, err=0x7fffffffc0f8)
    at /home/irfan/intake/libyang/src/plugins_types/date_and_time.c:105
#3  0x00007ffff7ddab0c in ly_value_validate (ctx=ctx@entry=0x0, node=node@entry=0x5555556c5490, value=<optimized out>, value_len=<optimized out>,
    format=format@entry=LY_VALUE_JSON, prefix_data=prefix_data@entry=0x0, hints=17) at /home/irfan/intake/libyang/src/tree_data_common.c:597
#4  0x00007ffff7decceb in lydjson_data_check_opaq (type_hint_p=0x7fffffffc1bc, snode=0x5555556c5490, lydctx=0x55555563a380) at /home/irfan/intake/libyang/src/parser_json.c:529
#5  lydjson_parse_instance (lydctx=lydctx@entry=0x55555563a380, parent=parent@entry=0x555555596e60, first_p=first_p@entry=0x555555596e98, snode=0x5555556c5490, ext=0x0,
    name=name@entry=0x7ffff78b7081 "discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth2\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12"..., name_len=18, prefix=0x0, prefix_len=0, status=0x7fffffffc2fc, node=0x7fffffffc338)
    at /home/irfan/intake/libyang/src/parser_json.c:1491
#6  0x00007ffff7dead40 in lydjson_subtree_r (lydctx=lydctx@entry=0x55555563a380, parent=0x555555596e60, first_p=0x555555596e98, parsed=parsed@entry=0x0)
    at /home/irfan/intake/libyang/src/parser_json.c:1766
#7  0x00007ffff7dec88a in lydjson_parse_instance_inner (node=0x7fffffffc578, status=0x7fffffffc53c, ext=0x0, snode=0x5555556c5410, lydctx=0x55555563a380)
    at /home/irfan/intake/libyang/src/parser_json.c:1429
#8  lydjson_parse_instance (lydctx=lydctx@entry=0x55555563a380, parent=parent@entry=0x55555558d290, first_p=first_p@entry=0x55555558d2c8, snode=<optimized out>, ext=0x0,
    name=name@entry=0x7ffff78b7073 "statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth2\",\"statistics\":{\"discontinuity-time\":\"2019-"..., name_len=10, prefix=0x0, prefix_len=0, status=0x7fffffffc53c, node=0x7fffffffc578)
    at /home/irfan/intake/libyang/src/parser_json.c:1522
#9  0x00007ffff7dead40 in lydjson_subtree_r (lydctx=lydctx@entry=0x55555563a380, parent=0x55555558d290, first_p=0x55555558d2c8, parsed=parsed@entry=0x0)
    at /home/irfan/intake/libyang/src/parser_json.c:1766
#10 0x00007ffff7dec88a in lydjson_parse_instance_inner (node=0x7fffffffc7b8, status=0x7fffffffc77c, ext=0x0, snode=0x5555556c45c0, lydctx=0x55555563a380)
    at /home/irfan/intake/libyang/src/parser_json.c:1429
#11 lydjson_parse_instance (lydctx=lydctx@entry=0x55555563a380, parent=parent@entry=0x55555559ce80, first_p=first_p@entry=0x55555559ceb8, snode=<optimized out>, ext=0x0,
    name=name@entry=0x7ffff78b7057 "interface\":[{\"name\":\"eth0\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth2\",\"statistics\":"..., name_len=9, prefix=0x0, prefix_len=0, status=0x7fffffffc77c, node=0x7fffffffc7b8)
    at /home/irfan/intake/libyang/src/parser_json.c:1522
#12 0x00007ffff7deb59f in lydjson_subtree_r (lydctx=lydctx@entry=0x55555563a380, parent=0x55555559ce80, first_p=0x55555559ceb8, parsed=parsed@entry=0x0)
    at /home/irfan/intake/libyang/src/parser_json.c:1742
#13 0x00007ffff7dec88a in lydjson_parse_instance_inner (node=0x7fffffffc9f8, status=0x7fffffffc9bc, ext=0x0, snode=0x5555556c4540, lydctx=0x55555563a380)
    at /home/irfan/intake/libyang/src/parser_json.c:1429
#14 lydjson_parse_instance (lydctx=lydctx@entry=0x55555563a380, parent=parent@entry=0x0, first_p=first_p@entry=0x7fffffffcd00, snode=<optimized out>, ext=0x0,
    name=name@entry=0x7ffff78b7012 "interfaces-state\":{\"@\":{\"ietf-origin:origin\":\"ietf-origin:unknown\"},\"interface\":[{\"name\":\"eth0\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statistics\":{\"discontin"..., name_len=16,
    prefix=0x7ffff78b7002 "ietf-interfaces:interfaces-state\":{\"@\":{\"ietf-origin:origin\":\"ietf-origin:unknown\"},\"interface\":[{\"name\":\"eth0\",\"statistics\":{\"discontinuity-time\":\"2019-10-29T09:43:12-00:00\"}},{\"name\":\"eth1\",\"statist"..., prefix_len=15, status=0x7fffffffc9bc, node=0x7fffffffc9f8)
    at /home/irfan/intake/libyang/src/parser_json.c:1522
#15 0x00007ffff7dead40 in lydjson_subtree_r (lydctx=lydctx@entry=0x55555563a380, parent=parent@entry=0x0, first_p=first_p@entry=0x7fffffffcd00, parsed=parsed@entry=0x7fffffffcb80)
    at /home/irfan/intake/libyang/src/parser_json.c:1766
#16 0x00007ffff7ded666 in lyd_parse_json (ctx=ctx@entry=0x5555555ab3b0, ext=ext@entry=0x0, parent=<optimized out>, parent@entry=0x0, first_p=first_p@entry=0x7fffffffcd00,
    in=in@entry=0x5555556cb930, parse_opts=parse_opts@entry=35979264, val_opts=0, int_opts=32, parsed=0x7fffffffcb80, subtree_sibling=0x7fffffffcb77 "", lydctx_p=0x7fffffffcb78)
    at /home/irfan/intake/libyang/src/parser_json.c:1895
#17 0x00007ffff7dd18fc in lyd_parse (ctx=ctx@entry=0x5555555ab3b0, ext=ext@entry=0x0, parent=parent@entry=0x0, first_p=first_p@entry=0x7fffffffcd00, in=0x5555556cb930,
    format=<optimized out>, format@entry=LYD_JSON, parse_opts=35979264, val_opts=0, op=0x0) at /home/irfan/intake/libyang/src/tree_data.c:150
#18 0x00007ffff7dd20d9 in lyd_parse_data (ctx=ctx@entry=0x5555555ab3b0, parent=parent@entry=0x0, in=<optimized out>, format=format@entry=LYD_JSON,
    parse_options=parse_options@entry=35979264, validate_options=validate_options@entry=0, tree=0x7fffffffcd00) at /home/irfan/intake/libyang/src/tree_data.c:247
#19 0x00007ffff7dd220a in lyd_parse_data_fd (ctx=0x5555555ab3b0, fd=<optimized out>, format=LYD_JSON, parse_options=35979264, validate_options=0, tree=0x7fffffffcd00)
    at /home/irfan/intake/libyang/src/tree_data.c:272
#20 0x00007ffff7f50f02 in srpds_json_load (mod=0x55555565fba0, ds=SR_DS_OPERATIONAL, cid=1, sid=1, UNUSED_xpaths=0x0, UNUSED_xpath_count=0, UNUSED_plg_data=0x0,
    mod_data=0x7fffffffcd00) at /home/irfan/opensource/sysrepo/src/plugins/ds_json.c:547
#21 0x00007ffff7f0e20d in sr_module_file_data_append (ly_mod=0x55555565fba0, ds_handle=0x55555952c190, ds=SR_DS_OPERATIONAL, cid=1, sid=1, xpaths=0x0, xpath_count=0,
    data=0x7fffffffcd68) at /home/irfan/opensource/sysrepo/src/common.c:5423
#22 0x00007ffff7f1d324 in sr_module_oper_data_load (mod=0x55555952c180, conn=0x55555556ada0, sid=0, mod_oper_data=0x0, data=0x7fffffffd038)
    at /home/irfan/opensource/sysrepo/src/modinfo.c:1318
#23 0x00007ffff7f1d765 in sr_module_oper_data_update (mod=0x55555952c180, orig_name=0x0, orig_data=0x0, operation_id=3, conn=0x55555556ada0, timeout_ms=1,
    get_oper_opts=SR_OPER_WITH_ORIGIN, data=0x7fffffffd038) at /home/irfan/opensource/sysrepo/src/modinfo.c:1459
#24 0x00007ffff7f20ff3 in sr_modinfo_module_data_load (mod_info=0x7fffffffd020, mod=0x55555952c180, sess=0x555555646d80, timeout_ms=1, get_oper_opts=SR_OPER_WITH_ORIGIN,
    run_cached_data_cur=0) at /home/irfan/opensource/sysrepo/src/modinfo.c:2801
#25 0x00007ffff7f2186d in sr_modinfo_data_load (mod_info=0x7fffffffd020, read_only=8, sess=0x555555646d80, timeout_ms=1, get_oper_opts=SR_OPER_WITH_ORIGIN)
    at /home/irfan/opensource/sysrepo/src/modinfo.c:3041
#26 0x00007ffff7f21ba2 in sr_modinfo_consolidate (mod_info=0x7fffffffd020, mod_lock=SR_LOCK_READ, mi_opts=136, sess=0x555555646d80, timeout_ms=1, ds_lock_timeout_ms=0,
    get_oper_opts=SR_OPER_WITH_ORIGIN) at /home/irfan/opensource/sysrepo/src/modinfo.c:3137
#27 0x00007ffff7ef45a8 in sr_get_data (session=0x555555646d80, xpath=0x5555555625c7 "/ietf-interfaces:interfaces", max_depth=0, timeout_ms=1, opts=16, data=0x7fffffffd140)
    at /home/irfan/opensource/sysrepo/src/sysrepo.c:3179
#28 0x00005555555616ea in test_date_time_scale (state=0x55555556a490) at /home/irfan/opensource/sysrepo/tests/test_oper_push.c:2982
#29 0x00007ffff7fa38f8 in ?? () from /lib/x86_64-linux-gnu/libcmocka.so.0
#30 0x00007ffff7fa3fdb in _cmocka_run_group_tests () from /lib/x86_64-linux-gnu/libcmocka.so.0
#31 0x0000555555561793 in main () at /home/irfan/opensource/sysrepo/tests/test_oper_push.c:3016
(gdb)

michalvasko added a commit that referenced this pull request Feb 17, 2025
@michalvasko
Copy link
Member

Thanks for that, it seems fine but I was not aware such a value was passed to the function so yes, the optimization was needed and I have improved the docs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants