Skip to content

Remove trace error introduced by tune bump and fix upload bug - #551

Merged
wagnerlmichael merged 19 commits into
masterfrom
mwagner/fix-trace-bug
Sep 10, 2026
Merged

wagnerlmichael merged 19 commits into
masterfrom
mwagner/fix-trace-bug

Conversation

@wagnerlmichael

@wagnerlmichael wagnerlmichael commented Aug 20, 2026 •

Copy link
Copy Markdown
Member

Running into the error

I stumbled upon this bug while attempting to confirm the upload stage warning bug discovered in the condo mse_cov PR.

My original objective was to reproduce this bug for the res model. First, I subsetted the CV hyperparam search and the training data to attempt to reproduce the mse_cov upload bug with less CV batch spend, but I was met with a different error - error message in cloudwatch

  | 2026-08-19T20:47:30.807Z | ✓ Estimating performance
  | 2026-08-19T20:47:30.848Z | ♥ Newest results: rmse=0.2871 (+/-0.000489)
  | 2026-08-19T20:47:30.851Z | Error: Cannot infer type from vector
  | 2026-08-19T20:47:30.851Z | Execution halted
  | 2026-08-19T20:47:31.258Z | ERROR: failed to reproduce 'train': failed to run: Rscript pipeline/01-train.R, exited with 1

Then, I kicked off a CV run off of master in an effort to see if this was a result of my CV shirink/subset, and the error was reproduced on main: error message in cloudwatch

  | 2026-08-20T07:31:11.179Z | ! No improvement for 15 iterations; returning current results.
  | 2026-08-20T07:31:11.182Z | Error: Cannot infer type from vector
  | 2026-08-20T07:31:11.183Z | Execution halted
  | 2026-08-20T07:31:12.153Z | ERROR: failed to reproduce 'train': failed to run: Rscript pipeline/01-train.R, exited with 1

Root cause

The problem is that there is a new trace column persisted in our new tune version. #533 upgraded tune from 1.x to 2.1.0. tune 2.x added a trace column to the .notes tibbles inside tuning results.

The column holds rlang call-stack objects, one per captured warning. At the end of CV, the train stage writes the raw tuning results to parquet:

lgbm_search %>%
  lightsnip::axe_tune_data() %>%
  arrow::write_parquet(paths$output$parameter_raw$local)

Arrow has no serialization for a list of call stacks, so the write fails with Cannot infer type from vector. The crash happens after tuning completes.

Any warning captured during tuning triggers the bug. The mse_cov objective guarantees warnings, because predict.lgb.Booster() warns once per predict call for custom objectives.

Verify solution works

This run with the fix successfully passes the train stage (but fails at the upload stage because that fix is being handled here, not in this PR).

Closes #539 and #552

@wagnerlmichael wagnerlmichael changed the title Add first draft of fix Add trace handling necessary due to tune package bump Aug 20, 2026
@wagnerlmichael wagnerlmichael changed the title Add trace handling necessary due to tune package bump Remove trace error introduced by tune bump Aug 20, 2026
@wagnerlmichael
wagnerlmichael marked this pull request as ready for review August 20, 2026 20:33

@wrridgeway wrridgeway left a comment •

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Alright, to make sure I'm understanding:

We've got two errors caused by the .notes column: one we already address in condos and we're addressing for the res avm here that is essentially us aggregating notes across iterations before uploading them to S3.

The second is a new column caused by an update in tune that added a new column for debugging which we're just dropping here.

This seems fine to me... I don't think we need to persist this column in s3 and athena. But, could we test printing the notes before this column is removed so that we can see it in cloudwatch if there's ever a tuning error?

@jeancochrane you might want to put eyes on this as well to confirm I'm thinking this through correctly.

@wagnerlmichael

Copy link
Copy Markdown
Member Author

We've got two errors caused by the .notes column: one we already address in condos and we're addressing for the res avm here that is essentially us aggregating notes across iterations before uploading them to S3.

The second is a new column caused by an update in tune that added a new column for debugging which we're just dropping here.

That's in line with my understanding!

This seems fine to me... I don't think we need to persist this column in s3 and athena. But, could we test printing the notes before this column is removed so that we can see it in cloudwatch if there's ever a tuning error?

@jeancochrane you might want to put eyes on this as well to confirm I'm thinking this through correctly.

I'll check it out, I'm currently investigating the contents of the trace column after Jean took a brief look at this PR and messaged me out of band

@wagnerlmichael

wagnerlmichael commented Aug 25, 2026 •

Copy link
Copy Markdown
Member Author

Some notes on the trace column and an alternative implementation:

This would have been my best shot at including the trace in the athena cv table. I think Billy's proposition is better for a few resons:

  • This would have added another column, which would have meant adding more to an already annoyingly complicated cv logs data model
  • Saving the trace wouldn't even help us on certain failures because a failure here likely means we would never even reach the upload stage
  • Billy's collect_notes idea buys us more verbose cloudwatch logging without making any schema changes
# Flattening each rlang trace to plain text keeps the diagnostic content in a
# form arrow CAN serialize. This is the candidate replacement for the
# select(-trace) line in 01-train: the 42 traces that serialize to ~5.7GB as
# rds (captured environments) come out to ~12KB of parquet as text.
axed_str <- lgbm_search %>%
  lightsnip::axe_tune_data() %>%
  mutate(.notes = map(
    .notes,
    ~ mutate(.x, trace = map_chr(trace, function(tr) {
      if (is.null(tr)) NA_character_ else paste(format(tr), collapse = "\n")
    }))
  ))
axed_str %>%
  tidyr::unnest(.notes) %>%
  select(any_of(c("id", ".iter")), location, type, trace)
axed_str_unnest$trace[1] |> cat()

This is an example of what the trace looks like after formatting it in a character format, which is necessary for inspection/persistence because they are originally rds trace types of objects with super high file size

▆
  1. ├─tune::tune_bayes(...)
  2. ├─tune:::tune_bayes.workflow(...)
  3. │ └─tune:::tune_bayes_workflow(...)
  4. │   └─tune::check_initial(...)
  5. │     ├─tune::tune_grid(...)
  6. │     └─tune:::tune_grid.workflow(...)
  7. │       └─tune:::tune_grid_workflow(...)
  8. │         └─tune:::tune_grid_loop(...)
  9. │           ├─rlang::eval_bare(cl)
 10. │           └─base::lapply(...) at [rlang/R/eval.R:96:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 11. │             └─tune (local) FUN(X[[i]], ...)
 12. │               ├─tune::.catch_and_log(...)
 13. │               │ └─tune:::catcher(.expr)
 14. │               │   └─rlang::try_fetch(...)
 15. │               │     ├─base::tryCatch(...) at [rlang/R/cnd-handlers.R:206:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 16. │               │     │ └─base (local) tryCatchList(expr, classes, parentenv, handlers)
 17. │               │     │   └─base (local) tryCatchOne(expr, names, parentenv, handlers[[1L]])
 18. │               │     │     └─base (local) doTryCatch(return(expr), name, parentenv, handler)
 19. │               │     └─base::withCallingHandlers(...)
 20. │               └─tune:::predict_all_types(current_wflow, pred_data, static)
 21. │                 └─tune:::predict_wrapper(...)
 22. │                   └─rlang::eval_tidy(cl)
 23. ├─parsnip::predict.model_fit(...) at [rlang/R/eval-tidy.R:121:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 24. │ ├─parsnip::predict_numeric(...) at [parsnip/R/predict.R:180:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 25. │ └─parsnip::predict_numeric.model_fit(...) at [parsnip/R/predict_numeric.R:59:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 26. │   └─rlang::eval_tidy(pred_call) at [parsnip/R/predict_numeric.R:36:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 27. ├─lightsnip::pred_lgb_reg_num(object = object, new_data = new_data) at [rlang/R/eval-tidy.R:121:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 28. │ ├─stats::predict(...) at [lightsnip/R/lightgbm.R:333:3](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 29. │ └─lightgbm:::predict.lgb.Booster(...)
 30. │   └─base::warning("Prediction types 'class' and 'response' are not supported for custom objectives.") at [lightgbm/R/lgb.Booster.R:1051:5](vscode-file://vscode-app/c:/Program%20Files/Positron/resources/app/out/vs/code/electron-browser/workbench/workbench.html#)
 31. ├─base::.signalSimpleWarning(...)
 32. │ └─base::withRestarts(...)
 33. │   └─base (local) withOneRestart(expr, restarts[[1L]])
 34. │     └─base (local) doWithOneRestart(return(expr), restart)
 35. └─rlang (local) `<fn>`(`<smplWrnn>`)

Comment thread pipeline/01-train.R Outdated
cat(note, "\n")
if (!is.null(trace)) cat(paste(format(trace), collapse = "\n"), "\n")
})

@wagnerlmichael wagnerlmichael Aug 26, 2026 •

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Implemented Billy's idea here.

Here is an example of an output produced from this code: cloudwatch logs. Navigate to the earlier portion of the logs (CV) and you'll see it.

It shows the trace for the mse_cov induced warning message, as trace messages come up for both warnings and error messages

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Hmm, I'm torn on this approach. I think it's sensible to print the warnings, but I also worry that we'll be printing and saving a huge number of extraneous tracebacks, since a warning trace that is common to all folds/iterations/locations will get printed on every fold/iteration/location. That might actually make the logs harder to deal with, since we'd have to wade through a whole bunch of noise.

What do you two think? I see a few options:

  1. Go with Michael's original idea, and strip the trace entirely
    • Keeps the logs as clean as possible, but makes it harder to debug warnings; we could perhaps mitigate this a bit by making it clear how to re-enable this warning logging if we need to debug in the future
  2. Try to deduplicate the warnings and traces even further, so that we don't print the same warning for every fold/iteration/location
    -Strikes a balance between verbosity and ability to debug, but I suspect the code to do this will be convoluted and hard to understand
  3. Only print warnings and traces for the first fold/iteration/location, assuming they will all be identical
    • Might be less convoluted than 2, but I have very low confidence that the underlying assumption (all folds/iterations/locations have identical warnings) is always true, since IIRC the sample can be different

What do you two think? I don't have super strong opinions here, especially since CV is a rarely used feature, so I'm happy to move forward with whatever approach the group decides on

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

I'm leaning towards option 1, here's what I'm thinking:

  • I'm having a trouble seeing a situation where a CV-related error happens, and we are significantly less equipped to deal with it because we didn't persists these traces
  • This data structure surrounding cv logging (for me) is complex and difficult to reason about, so I'd prefer to lean away from it instead of into it

We get a bottom line error message in cloudwatch regardless. And if that doesn't help us out enough, with some subsetting we can tease out a real stack trace locally, or even temporarily put some log printing code in the pipeline if we really need to troubleshoot

@jeancochrane jeancochrane Sep 2, 2026 •

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

I'm down for that, unless @wrridgeway objects! Happy to discuss this out loud today if it'd be faster.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Woof, yeah, that output is pretty rough. I'm inclined to go with option 1 as well, I don't think these trace notes actually help seeing what they look like in the logs. So long as we get an error that points us in the right direction we can just debug this issue locally.

Comment thread pipeline/06-upload.R
notes = paste(unique(note), collapse = "; "),
.groups = "drop"
),
by = c("id", ".iter")

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Same fix we implement in the condos PR

Comment thread params.yaml Outdated
# Should the train stage run full cross-validation? Otherwise, the model
# will be trained with the default hyperparameters specified below
cv_enable: false
cv_enable: true

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

TODO: revert to master. I used this to trim the CV runtime to test in the cloudwatch logs

@wagnerlmichael wagnerlmichael changed the title Remove trace error introduced by tune bump Remove trace error introduced by tune bump and fix upload bug Aug 31, 2026
Comment thread pipeline/06-upload.R Outdated
rename(., notes = .notes) %>%
tidyr::unnest(cols = notes) %>%
rename(notes = note)
read_parquet(paths$output$parameter_raw$local) %>%

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Question: is there a reason we can't use . here instead of re-reading the file?

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

I don't think so - 6fdba7a

@jeancochrane jeancochrane left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Thanks!

@wagnerlmichael
wagnerlmichael merged commit 8545a11 into master Sep 10, 2026
9 checks passed
@wagnerlmichael
wagnerlmichael deleted the mwagner/fix-trace-bug branch September 10, 2026 19:58
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.

Confirm and fix issue in res cv upload stage

3 participants