Skip to content
This repository was archived by the owner on Mar 12, 2020. It is now read-only.

Commit 05f9d75

Browse files
author
Eric Meyer
committed
Adds progress logging of changeset creation. Uses same progress log message formatting as Discovery Engine.
1 parent c2b0a02 commit 05f9d75

File tree

7 files changed

+633
-11
lines changed

7 files changed

+633
-11
lines changed

‎src/main/java/com/t11e/discovery/datatool/CreateActionRowCallbackHandler.java‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,7 @@ public class CreateActionRowCallbackHandler
4747
private String currentId;
4848
private Map<String, Object> currentItemProperties;
4949
private final ItemIdBuilder itemIdBuilder;
50+
private final ProgressLogger progress;
5051

5152
public CreateActionRowCallbackHandler(
5253
final NamedParameterJdbcOperations jdbcTemplate,
@@ -60,11 +61,13 @@ public CreateActionRowCallbackHandler(
6061
final Set<String> unscopedJsonColumns,
6162
final List<MergeColumns> mergeColumns,
6263
final List<SubQuery> subqueries,
63-
final boolean shouldRecordTimings)
64+
final boolean shouldRecordTimings,
65+
final ProgressLogger progress)
6466
{
6567
this.jdbcTemplate = jdbcTemplate;
6668
this.writer = writer;
6769
this.action = action;
70+
this.progress = progress;
6871
itemIdBuilder = new ItemIdBuilder(idColumn);
6972
this.providerColumn = StringUtils.lowerCase(providerColumn);
7073
this.kindColumn = StringUtils.lowerCase(kindColumn);
@@ -389,6 +392,7 @@ private void streamItem(final String id, final Map<String, Object> properties)
389392
throw new IllegalStateException("Cannot handle action of " + action);
390393
}
391394
}
395+
progress.worked(1);
392396
}
393397

394398
@Override

‎src/main/java/com/t11e/discovery/datatool/DeleteActionRowCallbackHandler.java‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,16 +14,19 @@ public class DeleteActionRowCallbackHandler
1414
private final ItemIdBuilder itemIdBuilder;
1515
private final String providerColumn;
1616
private final String kindColumn;
17+
private final ProgressLogger progress;
1718

1819
public DeleteActionRowCallbackHandler(
1920
final ChangesetWriter writer,
2021
final String idColumn,
2122
final String providerColumn,
22-
final String kindColumn)
23+
final String kindColumn,
24+
final ProgressLogger progress)
2325
{
2426
this.writer = writer;
2527
this.providerColumn = providerColumn;
2628
this.kindColumn = kindColumn;
29+
this.progress = progress;
2730
itemIdBuilder = new ItemIdBuilder(idColumn);
2831
}
2932

@@ -44,6 +47,7 @@ public void processRow(final ResultSet rs)
4447
{
4548
writer.removeItem(id);
4649
}
50+
progress.worked(1);
4751
}
4852
catch (final XMLStreamException e)
4953
{

‎src/main/java/com/t11e/discovery/datatool/ProgressLogger.java‎

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
package com.t11e.discovery.datatool;
2+
3+
public interface ProgressLogger
4+
{
5+
/**
6+
* Begins reporting progress.
7+
*/
8+
ProgressLogger begin(String description);
9+
10+
/**
11+
* Ends reporting progress.
12+
*/
13+
ProgressLogger done();
14+
15+
/**
16+
* Reports an amount of work performed.
17+
*/
18+
ProgressLogger worked(long worked);
19+
20+
/**
21+
* Modifies estimated amount of work.
22+
*/
23+
ProgressLogger setUnits(String unitSingle, String unitPlural);
24+
25+
/**
26+
* Modifies estimated amount of work.
27+
*/
28+
ProgressLogger setEstimatedWork(long estimatedWork, String unitSingle, String unitPlural);
29+
30+
/**
31+
* Sets description of work currently begin done.
32+
*/
33+
ProgressLogger setDescription(String description);
34+
35+
/**
36+
* Sets whether the progress is being prevented by a failure. It is
37+
* possible to unset a failure after it has been set. Failure does not imply
38+
* completion; {@link #done()} must still be called to flag completion.
39+
*/
40+
ProgressLogger setFailed(boolean failed);
41+
42+
/**
43+
* Reports an exception.
44+
*/
45+
ProgressLogger addException(Throwable throwable);
46+
}

‎src/main/java/com/t11e/discovery/datatool/ProgressLoggerSimpleJavaUtil.java‎

Lines changed: 254 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,254 @@
1+
package com.t11e.discovery.datatool;
2+
3+
import java.text.NumberFormat;
4+
import java.util.concurrent.TimeUnit;
5+
import java.util.logging.Level;
6+
import java.util.logging.Logger;
7+
8+
import org.apache.commons.lang.StringUtils;
9+
10+
public class ProgressLoggerSimpleJavaUtil
11+
implements ProgressLogger
12+
{
13+
private final NumberFormat format;
14+
private final Logger logger;
15+
private final Level level;
16+
/**
17+
* Don't log progress messages more often than this number of ms.
18+
*/
19+
private final long minLogIntervalNs;
20+
private boolean inProgress;
21+
private long startNs;
22+
private long progress;
23+
private String description;
24+
private long lastLogMessgeTime;
25+
private long lastProgress;
26+
private boolean failed;
27+
private String unitSingle;
28+
private String unitPlural;
29+
private long estimatedWork;
30+
31+
public ProgressLoggerSimpleJavaUtil(final Logger logger, final Level level, final long minLogIntervalMs)
32+
{
33+
format = NumberFormat.getNumberInstance();
34+
format.setMaximumFractionDigits(3);
35+
format.setGroupingUsed(true);
36+
this.logger = logger;
37+
this.level = level;
38+
minLogIntervalNs = TimeUnit.NANOSECONDS.convert(minLogIntervalMs, TimeUnit.MILLISECONDS);
39+
}
40+
41+
@Override
42+
public ProgressLogger begin(final String description)
43+
{
44+
if (inProgress)
45+
{
46+
setFailed(true);
47+
done();
48+
}
49+
inProgress = true;
50+
progress = 0;
51+
lastProgress = 0;
52+
estimatedWork = 0;
53+
startNs = System.nanoTime();
54+
this.description = description;
55+
logProgress(startNs, "[begin]");
56+
return this;
57+
}
58+
59+
@Override
60+
public ProgressLogger done()
61+
{
62+
inProgress = false;
63+
final long now = System.nanoTime();
64+
logProgress(now);
65+
failed = false;
66+
return this;
67+
}
68+
69+
@Override
70+
public ProgressLogger worked(final long worked)
71+
{
72+
progress += worked;
73+
maybeLogProgress();
74+
return this;
75+
}
76+
77+
@Override
78+
public ProgressLogger setUnits(final String unitSingle, final String unitPlural)
79+
{
80+
this.unitSingle = unitSingle;
81+
this.unitPlural = unitPlural;
82+
maybeLogProgress();
83+
return this;
84+
}
85+
86+
@Override
87+
public ProgressLogger setEstimatedWork(final long estimatedWork, final String unitSingle, final String unitPlural)
88+
{
89+
this.estimatedWork = estimatedWork;
90+
this.unitSingle = unitSingle;
91+
this.unitPlural = unitPlural;
92+
maybeLogProgress();
93+
return this;
94+
}
95+
96+
@Override
97+
public ProgressLogger setDescription(final String description)
98+
{
99+
this.description = description;
100+
maybeLogProgress();
101+
return this;
102+
}
103+
104+
@Override
105+
public ProgressLogger setFailed(final boolean failed)
106+
{
107+
this.failed = failed;
108+
maybeLogProgress();
109+
return this;
110+
}
111+
112+
@Override
113+
public ProgressLogger addException(final Throwable throwable)
114+
{
115+
final long now = System.nanoTime();
116+
final StringBuilder msg = new StringBuilder();
117+
formatProgressBar(msg, now);
118+
msg.append(" [exception]");
119+
logger.log(level, msg.toString(), throwable);
120+
lastLogMessgeTime = now;
121+
lastProgress = progress;
122+
return this;
123+
}
124+
125+
private void maybeLogProgress()
126+
{
127+
if (inProgress)
128+
{
129+
final long now = System.nanoTime();
130+
if (now - lastLogMessgeTime > minLogIntervalNs)
131+
{
132+
logProgress(now);
133+
}
134+
}
135+
}
136+
137+
private void logProgress(final long now, final String... extraLogContext)
138+
{
139+
final StringBuilder msg = new StringBuilder();
140+
formatProgressBar(msg, now);
141+
for (final String ctx : extraLogContext)
142+
{
143+
msg.append(" ").append(ctx);
144+
}
145+
logger.log(level, msg.toString());
146+
lastLogMessgeTime = now;
147+
lastProgress = progress;
148+
}
149+
150+
private void formatProgressBar(
151+
final StringBuilder buffer,
152+
final long nowNs)
153+
{
154+
long eta = 0;
155+
if (estimatedWork > 0)
156+
{
157+
if (progress > 0)
158+
{
159+
final long elapsed = nowNs - startNs;
160+
final long unitsLeft = estimatedWork - progress;
161+
eta = (long) (unitsLeft * (elapsed / (double) progress));
162+
}
163+
}
164+
final long timeDelta = nowNs - lastLogMessgeTime;
165+
final long workDelta = progress - lastProgress;
166+
167+
buffer.append(description);
168+
if (inProgress && estimatedWork == 0)
169+
{
170+
buffer.append("...");
171+
}
172+
final boolean estimation = estimatedWork > 0;
173+
if (estimation)
174+
{
175+
buffer.append(" [");
176+
final int barLength = 15;
177+
final int fillChars = (int) (((double) progress / estimatedWork) * barLength);
178+
for (int i = 0; i < barLength; i++)
179+
{
180+
buffer.append(i < fillChars ? '#' : '.');
181+
}
182+
buffer.append("]");
183+
}
184+
if (failed)
185+
{
186+
buffer.append(" [failed]");
187+
}
188+
if (!inProgress)
189+
{
190+
buffer.append(" [done]");
191+
}
192+
if (estimatedWork > 1)
193+
{
194+
final int pc = (int) ((progress / (double) estimatedWork) * 100);
195+
buffer.append(StringUtils.rightPad(String.valueOf(pc), 6));
196+
buffer.append("%");
197+
}
198+
if (estimation)
199+
{
200+
buffer.append(" [");
201+
final String s = format.format(estimatedWork);
202+
buffer.append(StringUtils.rightPad(format.format(progress), s.length()));
203+
buffer.append("/");
204+
buffer.append(s);
205+
buffer.append("]");
206+
}
207+
else if (progress > 0)
208+
{
209+
buffer.append(" [");
210+
buffer.append(format.format(progress));
211+
buffer.append("]");
212+
}
213+
final long workTime = nowNs - startNs;
214+
final long workTimeRounded = roundNs(workTime);
215+
if (workTimeRounded > 0)
216+
{
217+
buffer.append(" (");
218+
buffer.append(TimingUtil.formatTimingConcise(workTimeRounded, TimingUtil.UNITS_NS));
219+
if (inProgress)
220+
{
221+
final long etaRounded = roundNs(eta);
222+
if (etaRounded > 0)
223+
{
224+
buffer.append(", ETA ");
225+
buffer.append(TimingUtil.formatTimingConcise(etaRounded, TimingUtil.UNITS_NS));
226+
}
227+
}
228+
if (!inProgress && progress > 0)
229+
{
230+
buffer.append(", ");
231+
buffer.append(TimingUtil.formatItemTime(workTime, TimingUtil.UNITS_NS, progress, unitSingle, unitPlural));
232+
}
233+
final int unitsPerSec = inProgress
234+
? (timeDelta > 0
235+
? (int) (workDelta / (timeDelta / (1.0 * TimeUnit.NANOSECONDS.convert(1, TimeUnit.SECONDS)))) : 0)
236+
: (workTime > 0
237+
? (int) (progress / (workTime / (1.0 * TimeUnit.NANOSECONDS.convert(1, TimeUnit.SECONDS)))) : 0);
238+
if (unitsPerSec > 0)
239+
{
240+
buffer.append(", ");
241+
buffer.append(format.format(unitsPerSec));
242+
buffer.append(" ");
243+
buffer.append(unitPlural);
244+
buffer.append("/sec");
245+
}
246+
buffer.append(')');
247+
}
248+
}
249+
250+
private static long roundNs(final long workTime)
251+
{
252+
return workTime - (workTime % 1000000000);
253+
}
254+
}

‎src/main/java/com/t11e/discovery/datatool/SqlAction.java‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,28 @@ public String transform(final Object in)
4646
CollectionUtils.transform(unscopedJsonColumns, transformer);
4747
}
4848

49+
public String getChangesetElementType()
50+
{
51+
final String result;
52+
if ("create".equals(action))
53+
{
54+
result = "set-item";
55+
}
56+
else if ("add".equals(action))
57+
{
58+
result = "add-to-item";
59+
}
60+
else if ("delete".equals(action))
61+
{
62+
result = "remove-item";
63+
}
64+
else
65+
{
66+
result = action;
67+
}
68+
return result;
69+
}
70+
4971
public Set<String> getFilter()
5072
{
5173
return filter;

0 commit comments

Comments
 (0)