memrecycle no snprintf overhead #5463

jangorecki · 2022-09-14T22:11:22Z

closes #5424, closes #5366, closes #5371

issue:  1.14.2 vs  master vs  branch
#5424:  0.939s vs  1.725s vs  0.958s
#5366: 14.786s vs 26.515s vs 14.621s
#5371:  0.058s vs  0.050s vs  0.025s

code:

library(data.table)
set.seed(123L)
n = 1e4L
dt = data.table(id = seq_len(n),
                val = rnorm(n))

system.time(
  dt[, .(vs = (sum(val))), by = .(id)]
)


library(data.table)
N <- 1e8
n <- 1e6
set.seed(1L)
dt <- data.table(g = sample(seq_len(n), N, TRUE),
                 x = runif(N),
                 key = "g")
dt_mod <- copy(dt)
system.time(
  dt_mod[, N := .N, by = g]
)


library(data.table)
set.seed(1)
n <- 1e6
d1 <- abs(rnorm(n, sd = 4))
d2 <- as.integer(cumsum(d1))
tm <- as.POSIXct("2020-01-01 09:30:00") + d2
nIds <- 3
tmCol <- rep(tm, nIds)
idCol <- rep(c("a", "b", "c"), n)
f1 <- function() {
    dt <- data.table(tm = tmCol, v = 1, id = idCol)
    dt[, tm1 := tm - 40]
    dt[, tm2 := tm]
    dt[, rowNum := .I]
    dt[dt, .(vs = sum(v)), on = .(id, rowNum <= rowNum, tm >= tm1, tm < tm2), by = .EACHI]
}
system.time(
  f1()
)

codecov · 2022-09-14T22:23:02Z

Codecov Report

Merging #5463 (5840919) into master (052f8da) will increase coverage by 0.00%.
The diff coverage is 100.00%.

@@           Coverage Diff           @@
##           master    #5463   +/-   ##
=======================================
  Coverage   99.51%   99.51%           
=======================================
  Files          80       80           
  Lines       14771    14774    +3     
=======================================
+ Hits        14699    14702    +3     
  Misses         72       72

Impacted Files	Coverage Δ
src/assign.c	`99.85% <100.00%> (+<0.01%)`	⬆️

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more

ColeMiller1

Thanks, Jan. Simple yet effective approach to rollback the performance issues.

ben-schwen · 2022-09-17T11:46:54Z

Why do we not need targetDesc in the CHECK_RANGE macro?

data.table/src/assign.c

Lines 867 to 881 in ade6e57

    
           #define CHECK_RANGE(STYPE, RFUN, COND, FMT, TO, FMTVAL) {{                                                              \ 
        
             const STYPE *sd = (const STYPE *)RFUN(source);                                                                        \ 
        
             for (int i=0; i<slen; ++i) {                                                                                          \ 
        
               const STYPE val = sd[i+soff];                                                                                       \ 
        
               if (COND) {                                                                                                         \ 
        
                 const char *sType = sourceIsI64 ? "integer64" : type2char(TYPEOF(source));                                        \ 
        
                 const char *tType = targetIsI64 ? "integer64" : type2char(TYPEOF(target));                                        \ 
        
                 snprintf(memrecycle_message, MSGSIZE,                                                                             \ 
        
                   "%"FMT" (type '%s') at RHS position %d "TO" when assigning to type '%s' (%s)",                                  \ 
        
                   FMTVAL, sType, i+1, tType, targetDesc);                                                                         \ 
        
                 /* string returned so that rbindlist/dogroups can prefix it with which item of its list this refers to  */        \ 
        
                 break;                                                                                                            \ 
        
               }                                                                                                                   \ 
        
             }                                                                                                                     \ 
        
           } break; }

or is created in every possible branch before?

jangorecki · 2022-09-17T17:00:20Z

12 lines above is code which is still valid for the macro. Macro doesn't have own scope, it just substitutes code in existing scope, so the code 12 lines above is still used there.

MichaelChirico · 2022-09-19T06:54:16Z

great stuff!

can we blow up the examples for the fixes to #5424 and #5371? I worry about benchmarks lasting <1s

MichaelChirico · 2022-09-19T06:56:22Z

src/assign.c

@@ -845,6 +851,8 @@ const char *memrecycle(const SEXP target, const SEXP where, const int start, con
    warning(_("Coercing 'list' RHS to '%s' to match the type of %s."), type2char(TYPEOF(target)), targetDesc);
    source = PROTECT(coerceVector(source, TYPEOF(target))); protecti++;
  } else if ((TYPEOF(target)!=TYPEOF(source) || targetIsI64!=sourceIsI64) && !isNewList(target)) {
+    static char targetDesc[501];
+    snprintf(targetDesc, 500, colnum==0 ? _("target vector") : _("column %d named '%s'"), colnum, colname);


shouldn't this one be declared inside the GetVerbose()>=3 branch?

I think macro below needs it as well

but the macro only needs it inside its if(COND). So isn't this snprintf() indeed wasteful? This snprintf could be inside this GetVerbose()>=3 and then appear inside the CHECK_RANGE macro as well inside its if(COND). When I didn't see the snprintf inside the CHECK_RANGE that's why I wrote #5463 (review). So it would read better if targetDesc was populated right there in CHECK_RANGE next to where it is used?

That's correct. I moved it then inside the if branch.

MichaelChirico · 2022-09-19T06:59:21Z

Hey Jan, IIUC the issue is we are declaring a string buffer inside memrecycle, but it's inefficient because memrecycle might get called many (100s?) of times, so the fix is to only declare the buffer just as it's needed. This makes a bit of code duplication because we can't just re-use the one declaration of the buffer, but increases efficiency since the buffer is not typically needed.

Is that right? It would be helpful to summarize your fix in the PR description, this will especially make it easier when referring back to the PR in the future.

MichaelChirico · 2022-09-19T07:01:01Z

src/assign.c

@@ -730,6 +728,8 @@ const char *memrecycle(const SEXP target, const SEXP where, const int start, con
          for (int i=0; i<slen; ++i) {
            const int val = sd[i+soff];
            if ((val<1 && val!=NA_INTEGER) || val>nlevel) {
+              static char targetDesc[501];  // from 1.14.1 coerceAs reuses memrecycle for a target vector, PR#4491


maybe wrap this into a helper function to save some duplication?

Could be, but I am fine either way

jangorecki · 2022-09-19T07:32:02Z

~~Yes, your are correct.~~ Personally I could even remove this declaration all together by keeping verbose message more obscure.
You are welcome to follow up here improvements, but keeping change minimal is also a plus.
I couldn't really reproduce time issue on #5371. As for other two, could be bigger, but this is good enough to confirm that regression introduced got fixed.

mattdowle

Great that you identified this, all the testing and benchmarks fit with the fix.

However, regarding the thought that it's the allocation?

Is that right?
Yes, your are correct.

No that's wrong. The allocation is declared static. Please look up what that is. We do that quite a lot in data.table and needs to be understood. To copy that down and repeat conveys to readers of the code that the static keyword isn't understood. So that needs to be put back at the top just once. The slow down will all be in the snprintf call itself.

Personally I could even remove this declaration all together by keeping verbose message more obscure.

Yes remove the declaration and snprintf, agree, but not make the message more obscure. Could repeat the ternary in each of the messages, or wrap that ternary in a macro. With the ternary I think I was trying to match previous messages maybe. Leaving implementation details aside do we agree that the column %d named '%s' part is better and more useful to provide to user when we can? It would be a shame to lose that part.

jangorecki · 2022-10-12T09:42:52Z

Yes, static wasn't understood.

As for removing snprintf

snprintf(targetDesc, 500, colnum==0 ? _("target vector") : _("column %d named '%s'"), colnum, colname);
error(_("Assigning factor numbers to %s. But %d is outside the level range [1,%d]"), targetDesc, val, nlevel);

If colnum would be a char, then we could set it to "", together with colname="" and then we could turn"target vector" into "target vector%s%s" (so two %s do nothing here). But as the colnum is not a char, we cannot really do it, and we are left with variable number of values to substitute in string. That leads to a temporary targetDesc object, or branching on top and duplicating error() call.

I started to removing targetDesc and extra snprintf calls but it doesn't look better IMO. Code is much less clear by having those big ternary operators everywhere.

colnum==0 ? Rprintf(_("Zero-copy coerce when assigning '%s' to '%s' target vector.\n"),
                          sourceIsI64 ? "integer64" : type2char(TYPEOF(source)),
                          targetIsI64 ? "integer64" : type2char(TYPEOF(target))) :
                  Rprintf(_("Zero-copy coerce when assigning '%s' to '%s' column %d named '%s'.\n"),
                          sourceIsI64 ? "integer64" : type2char(TYPEOF(source)),
                          targetIsI64 ? "integer64" : type2char(TYPEOF(target)),
                          colnum, colname);

colnum==0 ? snprintf(memrecycle_message, MSGSIZE,                                                                             \
        "%"FMT" (type '%s') at RHS position %d "TO" when assigning to type '%s' (target vector)",                                  \
        FMTVAL, sType, i+1, tType) : snprintf(memrecycle_message, MSGSIZE,                                                                             \
        "%"FMT" (type '%s') at RHS position %d "TO" when assigning to type '%s' (column %d named '%s')",                                  \
        FMTVAL, sType, i+1, tType, colnum, colname);                                                                         \

As the performance regression is fixed, maybe we can leave it as is? declaration of static char TargetDesc has been taken out from memrecycle.

mattdowle

[ This comment is supposed to be attached to the targetDesc inside the CHECK_RANGE definition. GH won't give me "+" to comment on that line because it's in a block that hasn't changed it seems? ]

How does this targetDesc get populated now? If I'm right that it doesn't, does that mean we're missing a test or the test is insufficient?

jangorecki · 2022-10-13T08:37:03Z

snprintf calls are still there to populate it.

mattdowle · 2022-10-13T18:40:50Z

Btw, the commit message static declares once would have been better as declare static once. The commit messages are suppose to describe what the commit does and if I look back in future at that, I won't know what that means. Perhaps in your mind you're describing a fact in the commit message, whereas I'm looking for a description of what the commit does. Or maybe it was just English.

mattdowle · 2022-10-13T23:43:16Z

I see now how that targetDesc in CHECK_RANGE gets populated, thanks. (Aside: maybe the #define CHECK_RANGE should be indented so that it's clearer that's part of that if() branch.) But now I reopened comment above and added further up there: #5463 (comment). Adding this new comment to be sure you see the reopened comment up there.

mattdowle · 2022-10-14T00:01:20Z

Assuming I'm right this time that that snprintf should be moved inside those if()s, then to avoid confusion in the future and to avoid the need to repeat the snprintf and in the correct way too, wherever targetDesc is passed as an argument currently to error()/warning()/Rprintf()/snprintf(), it could be a function call targetDesc() instead. That function call would populate the targetDesc storage and return targetDesc. That way there can be no doubt that the snprintf() to make targetDesc is only computed when needed, and is also consistent across all usage.

jangorecki · 2022-10-14T09:20:57Z

I pushed improvement for now to address your comment about if condition in CHECK_RANGE.
targetDesc() is a good idea, but till Monday I won't have time to touch that.

…voided

mattdowle · 2022-10-14T11:38:04Z

Thanks Jan. I did the targetDesc(). All good?

…datatable#5463

GitHub Action + atime test to observe the performance regression introduced by PR Rdatatable#4491 and fixed by PR Rdatatable#5463

memrecycle no snprintf overhead

ade6e57

jangorecki requested review from mattdowle and ColeMiller1 September 14, 2022 22:11

ColeMiller1 approved these changes Sep 15, 2022

View reviewed changes

MichaelChirico reviewed Sep 19, 2022

View reviewed changes

mattdowle added this to the 1.14.5 milestone Oct 12, 2022

mattdowle requested changes Oct 12, 2022

View reviewed changes

static declares once, feedback from Matt

2ff0039

mattdowle reviewed Oct 13, 2022

View reviewed changes

mattdowle added the dev label Oct 14, 2022

populate targetDesc closer to actual use

90dd45d

mattdowle added 2 commits October 14, 2022 05:31

change targetDesc to be a function call so repeated snprintf can be a…

7da3d62

…voided

indent macro definitions

9319570

mattdowle added 2 commits October 14, 2022 12:56

Merge branch 'master' into memrecycle-no-snprintf

a5694f9

added news item note thanking everyone involved here

5840919

mattdowle approved these changes Oct 14, 2022

View reviewed changes

mattdowle merged commit 19b7866 into master Oct 14, 2022

mattdowle deleted the memrecycle-no-snprintf branch October 14, 2022 19:41

tdhock restored the memrecycle-no-snprintf branch September 26, 2023 17:31

jangorecki modified the milestones: 1.14.9, 1.15.0 Oct 29, 2023

This was referenced Nov 11, 2023

Issue 5366 plotting is giving me a linear graph DorisAmoakohene/Researchwork_Rdata.table#2

Closed

Issue 5371 plotting is giving me a linear graph DorisAmoakohene/Researchwork_Rdata.table#3

Open

Anirban166 added a commit to Anirban166/data.table that referenced this pull request Mar 19, 2024

Added a test case which is not relevant or related to Rdatatable#4491/R…

ef2db64

…datatable#5463

Anirban166 mentioned this pull request Mar 19, 2024

GitHub Action + atime test to observe the performance regression introduced by PR #4491 and fixed by PR #5463 Anirban166/data.table#2

Merged

Anirban166 mentioned this pull request Apr 3, 2024

Certain commit SHAs have issues when getting installed via atime_versions_install tdhock/atime#38

Closed

MichaelChirico mentioned this pull request Apr 23, 2024

Move some setDT validation checks to C #5427

Merged

tdhock mentioned this pull request May 31, 2024

adding an atime test case Performance Regression with .N and := #PR5463 #6160

Closed

tdhock mentioned this pull request Jul 18, 2024

adding an atime test case Performance Regression with .N and := #PR5463 #6169

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

memrecycle no snprintf overhead #5463

memrecycle no snprintf overhead #5463

jangorecki commented Sep 14, 2022 •

edited

Loading

codecov bot commented Sep 14, 2022 •

edited

Loading

ColeMiller1 left a comment

ben-schwen commented Sep 17, 2022

jangorecki commented Sep 17, 2022

MichaelChirico commented Sep 19, 2022

MichaelChirico Sep 19, 2022

jangorecki Sep 19, 2022

mattdowle Oct 13, 2022

jangorecki Oct 14, 2022

MichaelChirico commented Sep 19, 2022

MichaelChirico Sep 19, 2022

jangorecki Sep 19, 2022

jangorecki commented Sep 19, 2022 •

edited

Loading

mattdowle left a comment

jangorecki commented Oct 12, 2022 •

edited

Loading

mattdowle left a comment •

edited

Loading

jangorecki commented Oct 13, 2022

mattdowle commented Oct 13, 2022 •

edited

Loading

mattdowle commented Oct 13, 2022 •

edited

Loading

mattdowle commented Oct 14, 2022 •

edited

Loading

jangorecki commented Oct 14, 2022

mattdowle commented Oct 14, 2022

memrecycle no snprintf overhead #5463

memrecycle no snprintf overhead #5463

Conversation

jangorecki commented Sep 14, 2022 • edited Loading

codecov bot commented Sep 14, 2022 • edited Loading

Codecov Report

ColeMiller1 left a comment

Choose a reason for hiding this comment

ben-schwen commented Sep 17, 2022

jangorecki commented Sep 17, 2022

MichaelChirico commented Sep 19, 2022

MichaelChirico Sep 19, 2022

Choose a reason for hiding this comment

jangorecki Sep 19, 2022

Choose a reason for hiding this comment

mattdowle Oct 13, 2022

Choose a reason for hiding this comment

jangorecki Oct 14, 2022

Choose a reason for hiding this comment

MichaelChirico commented Sep 19, 2022

MichaelChirico Sep 19, 2022

Choose a reason for hiding this comment

jangorecki Sep 19, 2022

Choose a reason for hiding this comment

jangorecki commented Sep 19, 2022 • edited Loading

mattdowle left a comment

Choose a reason for hiding this comment

jangorecki commented Oct 12, 2022 • edited Loading

mattdowle left a comment • edited Loading

Choose a reason for hiding this comment

jangorecki commented Oct 13, 2022

mattdowle commented Oct 13, 2022 • edited Loading

mattdowle commented Oct 13, 2022 • edited Loading

mattdowle commented Oct 14, 2022 • edited Loading

jangorecki commented Oct 14, 2022

mattdowle commented Oct 14, 2022

jangorecki commented Sep 14, 2022 •

edited

Loading

codecov bot commented Sep 14, 2022 •

edited

Loading

jangorecki commented Sep 19, 2022 •

edited

Loading

jangorecki commented Oct 12, 2022 •

edited

Loading

mattdowle left a comment •

edited

Loading

mattdowle commented Oct 13, 2022 •

edited

Loading

mattdowle commented Oct 13, 2022 •

edited

Loading

mattdowle commented Oct 14, 2022 •

edited

Loading