Hi everyone,
I may have found a bug, I thought I’d share in case it helps anyone else. We initially thought it was an issue with our installation so spent some time debugging.
Behaviour
When applying a JSON process to a project we had a column that was removed from our template. Applying and running the old JSON causes an Invalid JSON exception (removing a column that does not exist), after which attempts to manually change data in the project (removing a column that does exist) fails.
Expected behaviour
I would have expected the error to be noted, but to roll back and not affect the behaviour of the project.
Tech stack
Observed in OpenRefine 3.9.3 and 3.9.5 running on Windows 11 using Firefox.
Steps to recreate
Create a new project that includes the column “Format” but not “Column”.
Apply a JSON based process that deletes columns Format and Column.
(eg.
[
{
"op": "core/column-removal",
"columnName": "Format",
"description": "Remove column Format"
},
{
"op": "core/column-removal",
"columnName": "Column",
"description": "Remove column Column"
}
]
Apply the JSON to the project. (This should cause an error “java.lang.Exception: No column named Column” in red on the Apply window)
Attempt to manually delete the other column. This fails with an alert containing the same error for the new column name (java.lang.Exception: No column named Format).
Recreating the project from scratch and applying the JSON without the bad command fixes the issue.
Console output
`02:07:29.240 [ refine_server] Java runtime version 11.0.28+6 from java.home: C:\Program Files\OpenRefine-3.9.5\server\target\jre (0ms)
02:07:29.247 [ refine_server] Java VM: Eclipse Adoptium OpenJDK 64-Bit Server VM 11.0.28+6 mixed mode (7ms)
02:07:29.247 [ refine_server] Starting Server bound to http://127.0.0.1:3333 (0ms)
02:07:29.247 [ refine_server] refine.memory size: JVM Max heap: 1024.0 MBytes (0ms)
02:07:29.308 [ refine_server] Initializing context: '/' from 'C:\Program Files\OpenRefine-3.9.5\webapp' (60ms)
02:07:32.060 [ refine] Starting OpenRefine 3.9.5 [TRUNK] ... (2751ms)
02:07:32.060 [ refine] Initializing FileProjectManager with data dir: C:\Users\sbourke\AppData\Roaming\OpenRefine (0ms)
02:07:34.594 [ NER-extension] Initializing service manager (2534ms)
02:07:34.649 [ NER-extension] Initializing commands, changes, and operations (55ms)
02:07:34.672 [ NER-extension] Initializing client resources (22ms)
02:07:35.757 [ refine] POST /command/core/load-language (1084ms)
02:07:35.797 [ refine] GET /command/core/get-preference (40ms)
02:07:35.817 [ refine] POST /command/core/load-language (20ms)
02:07:35.830 [ refine] POST /command/core/load-language (12ms)
02:07:36.921 [ refine] GET /command/core/get-importing-configuration (1091ms)
02:07:36.939 [ refine] GET /command/core/get-all-project-tags (18ms)
02:07:36.955 [ refine] GET /command/core/get-all-project-metadata (15ms)
02:07:37.281 [ refine] GET /command/core/get-csrf-token (326ms)
02:07:37.305 [ refine] GET /command/core/get-languages (24ms)
02:07:37.465 [ refine] GET /command/core/get-version (160ms)
02:07:37.471 [ refine] GET /command/core/get-version (5ms)
02:07:37.595 [ refine] GET /command/database/saved-connection (124ms)
02:07:37.601 [ refine] GET /command/core/get-preference (6ms)
02:08:33.686 [ refine] POST /command/core/create-importing-job (56084ms)
02:08:33.698 [ refine] POST /command/core/importing-controller (12ms)
02:08:34.699 [ refine] POST /command/core/get-importing-job-status (1000ms)
02:08:34.730 [ refine] GET /command/core/get-all-project-tags (31ms)
02:08:34.751 [ refine] POST /command/core/importing-controller (20ms)
02:08:34.836 [ refine] POST /command/core/importing-controller (85ms)
02:08:34.871 [ refine] POST /command/core/get-models (34ms)
02:08:34.886 [ refine] POST /command/core/get-rows (15ms)
02:08:45.441 [ refine] POST /command/core/importing-controller (10555ms)
02:08:46.502 [ refine] POST /command/core/get-importing-job-status (1061ms)
02:08:47.356 [ refine] POST /command/core/load-language (853ms)
02:08:47.369 [ refine] GET /command/core/get-preference (13ms)
02:08:47.369 [ refine] GET /command/core/get-preference (13ms)
02:08:47.392 [ refine] POST /command/core/load-language (23ms)
02:08:47.400 [ refine] POST /command/core/load-language (7ms)
02:08:47.448 [ refine] GET /command/core/get-project-metadata (47ms)
02:08:47.449 [ refine] GET /command/core/get-models (1ms)
02:08:47.451 [ refine] GET /command/core/get-all-preferences (2ms)
02:08:47.503 [ refine] GET /command/core/get-history (51ms)
02:08:47.506 [ refine] POST /command/core/get-rows (3ms)
02:08:47.513 [ refine] GET /command/core/get-history (7ms)
02:08:47.587 [ refine] GET /command/core/get-preference (74ms)
02:08:56.621 [ refine] POST /command/core/load-language (9034ms)
02:08:56.631 [ refine] GET /command/core/get-preference (9ms)
02:08:56.638 [ refine] POST /command/core/load-language (7ms)
02:08:56.646 [ refine] POST /command/core/load-language (7ms)
02:08:56.739 [ refine] GET /command/core/get-importing-configuration (92ms)
02:08:56.758 [ refine] GET /command/core/get-all-project-tags (18ms)
02:08:56.765 [ refine] GET /command/core/get-all-project-metadata (7ms)
02:08:56.953 [ refine] GET /command/core/get-csrf-token (188ms)
02:08:56.968 [ refine] GET /command/core/get-languages (14ms)
02:08:57.041 [ refine] GET /command/core/get-version (72ms)
02:08:57.054 [ refine] GET /command/core/get-version (13ms)
02:08:57.135 [ refine] GET /command/database/saved-connection (81ms)
02:08:57.138 [ refine] GET /command/core/get-preference (3ms)
02:09:05.032 [ refine] POST /command/core/create-importing-job (7893ms)
02:09:05.043 [ refine] POST /command/core/importing-controller (11ms)
02:09:06.050 [ refine] POST /command/core/get-importing-job-status (1007ms)
02:09:06.061 [ refine] GET /command/core/get-all-project-tags (11ms)
02:09:06.086 [ refine] POST /command/core/importing-controller (25ms)
02:09:06.979 [ refine] POST /command/core/importing-controller (892ms)
02:09:06.979 [..e.io.FileProjectManager] Saving all modified projects ... (0ms)
02:09:06.979 [ FileProjectManager] (Re)creating missing project directory - C:\Users\sbourke\AppData\Roaming\OpenRefine\2665481807629.project (0ms)
02:09:07.001 [ project_utilities] Saved project '2665481807629' (22ms)
02:09:07.135 [ refine] POST /command/core/get-models (134ms)
02:09:07.147 [ refine] POST /command/core/get-rows (11ms)
02:09:10.719 [ refine] POST /command/core/importing-controller (3572ms)
02:09:11.726 [ refine] POST /command/core/get-importing-job-status (1006ms)
02:09:12.369 [ refine] POST /command/core/load-language (643ms)
02:09:12.380 [ refine] GET /command/core/get-preference (11ms)
02:09:12.381 [ refine] GET /command/core/get-preference (0ms)
02:09:12.402 [ refine] POST /command/core/load-language (21ms)
02:09:12.410 [ refine] POST /command/core/load-language (8ms)
02:09:12.486 [ refine] GET /command/core/get-project-metadata (75ms)
02:09:12.486 [ refine] GET /command/core/get-models (75ms)
02:09:12.487 [ refine] GET /command/core/get-all-preferences (0ms)
02:09:12.536 [ refine] GET /command/core/get-history (49ms)
02:09:12.537 [ refine] POST /command/core/get-rows (1ms)
02:09:12.543 [ refine] GET /command/core/get-history (5ms)
02:09:12.607 [ refine] GET /command/core/get-preference (63ms)
02:09:37.003 [ refine] GET /command/core/get-csrf-token (24396ms)
02:09:37.011 [ refine] POST /command/core/apply-operations (8ms)
02:09:37.057 [ FileProjectManager] (Re)creating missing project directory - C:\Users\sbourke\AppData\Roaming\OpenRefine\2197447303236.project (46ms)
02:09:37.125 [ command] Exception caught (67ms)
java.lang.Exception: No column named Column
at com.google.refine.operations.column.ColumnRemovalOperation.createHistoryEntry(ColumnRemovalOperation.java:77)
at com.google.refine.model.AbstractOperation$1.createHistoryEntry(AbstractOperation.java:80)
at com.google.refine.process.QuickHistoryEntryProcess.performImmediate(QuickHistoryEntryProcess.java:72)
at com.google.refine.process.ProcessManager.queueProcess(ProcessManager.java:84)
at com.google.refine.commands.history.ApplyOperationsCommand.doPost(ApplyOperationsCommand.java:81)
at com.google.refine.RefineServlet.service(RefineServlet.java:187)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1410)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:529)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1570)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:790)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1543)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at com.google.refine.ValidateHostHandler.handle(ValidateHostHandler.java:93)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.Server.handle(Server.java:563)
at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
02:10:03.142 [ refine] POST /command/core/apply-operations (26017ms)
02:10:03.146 [ command] Exception caught (3ms)
java.lang.Exception: No column named Format
at com.google.refine.operations.column.ColumnRemovalOperation.createHistoryEntry(ColumnRemovalOperation.java:77)
at com.google.refine.model.AbstractOperation$1.createHistoryEntry(AbstractOperation.java:80)
at com.google.refine.process.QuickHistoryEntryProcess.performImmediate(QuickHistoryEntryProcess.java:72)
at com.google.refine.process.ProcessManager.queueProcess(ProcessManager.java:84)
at com.google.refine.commands.history.ApplyOperationsCommand.doPost(ApplyOperationsCommand.java:81)
at com.google.refine.RefineServlet.service(RefineServlet.java:187)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1410)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:529)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1570)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:790)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1543)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at com.google.refine.ValidateHostHandler.handle(ValidateHostHandler.java:93)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
at org.eclipse.jetty.server.Server.handle(Server.java:563)
at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
02:12:33.407 [..e.io.FileProjectManager] Saving some modified projects ... (150260ms)
02:12:33.418 [ project_utilities] Saved project '2197447303236' (11ms)
