22284264868

Committed 22 Feb 2026 08:00PM UTC coverage: 70.75% (+0.3%) from 70.474%

Build # 22284264868

Build Type

Pull #1714

github

Committed by

web-flow

Commit Message

Merge 98f01421f into 379acdc9d

Pull Request Pull Request #1714: #404: #1713: advanced logging

Run Details

4063 of 6346 branches covered (64.02%)

Branch coverage included in aggregate %.

10636 of 14430 relevant lines covered (73.71%)

3.1 hits per line

Source File
Press 'n' to go to next uncovered line, 'b' for previous

68.16

cli/src/main/java/com/devonfw/tools/ide/step/StepImpl.java

package com.devonfw.tools.ide.step;

import java.time.Duration;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.event.Level;

import com.devonfw.tools.ide.context.AbstractIdeContext;
import com.devonfw.tools.ide.context.IdeContext;
import com.devonfw.tools.ide.log.IdeLogLevel;

/**
 * Regular implementation of {@link Step}.
 */
public final class StepImpl implements Step {

  private static final Logger LOG = LoggerFactory.getLogger(StepImpl.class);

  private final AbstractIdeContext context;

  private final StepImpl parent;

  private final String name;

  private final Object[] params;

  private final List<StepImpl> children;

  private final long start;

  private final boolean silent;

  private Boolean success;

  private String errorMessage;

  private long duration;

  /**
   * Creates and starts a new {@link StepImpl}.
   *
   * @param context the {@link IdeContext}.
   * @param parent the {@link #getParent() parent step}.
   * @param name the {@link #getName() step name}.
   * @param silent the {@link #isSilent() silent flag}.
   * @param params the parameters. Should have reasonable {@link Object#toString() string representations}.
   */
  public StepImpl(AbstractIdeContext context, StepImpl parent, String name, boolean silent, Object... params) {

    super();
    this.context = context;
    this.parent = parent;
    this.name = name;
    this.params = params;
    this.silent = silent;
    this.children = new ArrayList<>();
    this.start = System.currentTimeMillis();
    if (parent != null) {
      parent.children.add(this);
    }
    if (params.length == 0) {
      LOG.trace("Starting step {}...", name);
    } else {
      LOG.trace("Starting step {} with params {}...", name, Arrays.toString(params));
    }
    if (!this.silent) {
      LOG.info(IdeLogLevel.STEP.getSlf4jMarker(), "Start: {}", name);
    }
  }

  @Override
  public StepImpl getParent() {

    return this.parent;
  }

  @Override
  public String getName() {

    return this.name;
  }

  @Override
  public Object getParameter(int i) {

    if ((i < 0) || (i >= this.params.length)) {
      return null;
    }
    return this.params[i];
  }

  @Override
  public int getParameterCount() {

    return this.params.length;
  }

  @Override
  public boolean isSilent() {

    return this.silent;
  }

  @Override
  public long getDuration() {

    return this.duration;
  }

  @Override
  public Boolean getSuccess() {

    return this.success;
  }

  @Override
  public void success(String message, Object... args) {

    end(Boolean.TRUE, null, false, message, args);
  }

  @Override
  public void error(Throwable error, boolean suppress, String message, Object... args) {

    end(Boolean.FALSE, error, suppress, message, args);
  }

  @Override
  public void close() {

    end(null, null, false, null, null);
  }

  private void end(Boolean newSuccess, Throwable error, boolean suppress, String message, Object[] args) {

    boolean firstCallOfEnd = (this.success == null);
    if (!firstCallOfEnd) {
      assert (this.duration > 0);
      if ((newSuccess != null) && (newSuccess != this.success)) {
        LOG.warn("Step '{}' already ended with {} and now ended again with {}.", this.name, this.success, newSuccess);
      } else {
        return;
      }
    }
    long delay = System.currentTimeMillis() - this.start;
    if (delay == 0) {
      delay = 1;
    }
    if (newSuccess == null) {
      newSuccess = Boolean.FALSE;
    }
    if (!Boolean.FALSE.equals(this.success)) { // never allow a failed step to change to success
      this.duration = delay;
      this.success = newSuccess;
    }
    if (newSuccess.booleanValue()) {
      assert (error == null);
      if (message != null) {
        LOG.info(IdeLogLevel.SUCCESS.getSlf4jMarker(), message, args);
      } else if (!this.silent) {
        LOG.info(IdeLogLevel.SUCCESS.getSlf4jMarker(), "Successfully ended step '{}'.", this.name);
      }
      LOG.debug("Step '{}' ended successfully.", this.name);
    } else {
      Level level;
      if ((message != null) || (error != null)) {
        if (suppress) {
          if (error != null) {
            this.errorMessage = error.toString();
          } else {
            this.errorMessage = message;
          }
          level = Level.DEBUG;
        } else {
          if (message == null) {
            message = error.getMessage();
          }
          if (args == null) {
            LOG.atError().setCause(error).log(message);
          } else {
            LOG.atError().setCause(error).log(message, args);
          }
          if (error == null) {
            level = Level.DEBUG;
          } else {
            level = Level.ERROR;
          }
        }
      } else {
        level = Level.INFO;
      }
      LOG.atLevel(level).log("Step '{}' ended with failure.", this.name);
    }
    if (firstCallOfEnd) {
      this.context.endStep(this);
    }
  }

  /**
   * Logs the summary of this {@link Step}. Should typically only be called on the top-level {@link Step}.
   *
   * @param suppressSuccess - {@code true} to suppress the success message, {@code false} otherwise.
   */
  public void logSummary(boolean suppressSuccess) {

    if (LOG.isTraceEnabled()) {
      LOG.trace(toString());
    }
    if (this.context.isQuietMode() || (this.children.isEmpty())) {
      return;
    }
    StepSummary summary = new StepSummary();
    logErrorSummary(0, summary);
    if (summary.getError() == 0) {
      if (!suppressSuccess) {
        LOG.info(IdeLogLevel.SUCCESS.getSlf4jMarker(), "Successfully completed {}", getNameWithParams());
      }
    } else {
      LOG.error(summary.toString());
    }
  }

  private void logErrorSummary(int depth, StepSummary summary) {

    boolean failure = isFailure();
    summary.add(failure);
    if (failure) {
      String error = this.errorMessage;
      if (error == null) {
        error = "unexpected error";
      }
      LOG.error("{}Step '{}' failed: {}", getIndent(depth), getNameWithParams(), error);
    }
    depth++;
    for (StepImpl child : this.children) {
      child.logErrorSummary(depth, summary);
    }
  }

  private String getNameWithParams() {

    if ((this.params == null) || (this.params.length == 0)) {
      return this.name;
    }
    StringBuilder sb = new StringBuilder(this.name.length() + 3 + this.params.length * 6);
    getNameWithParams(sb);
    return sb.toString();
  }

  private void getNameWithParams(StringBuilder sb) {

    sb.append(this.name);
    sb.append(" (");
    String seperator = "";
    if (this.params != null) {
      for (Object param : this.params) {
        sb.append(seperator);
        sb.append(param);
        seperator = ",";
      }
    }
    sb.append(')');
  }

  private void append(int depth, long totalDuration, long parentDuration, StringBuilder sb) {

    // indent
    sb.append(getIndent(depth));
    getNameWithParams(sb);
    sb.append(' ');
    if (this.success == null) {
      sb.append("is still running or was not properly ended due to programming error not using finally block ");
    } else {
      if (this.success.booleanValue()) {
        sb.append("succeeded after ");
      } else {
        sb.append("failed after ");
      }
      sb.append(Duration.ofMillis(this.duration));
    }
    if (this.duration < totalDuration) {
      sb.append(" ");
      double percentageBase = this.duration * 100;
      double totalPercentage = percentageBase / totalDuration;
      sb.append(totalPercentage);
      sb.append("% of total ");
      if (parentDuration < totalDuration) {
        double parentPercentage = percentageBase / parentDuration;
        sb.append(parentPercentage);
        sb.append("% of parent");
      }
    }
    sb.append('\n');
    int childDepth = depth + 1;
    for (StepImpl child : this.children) {
      child.append(childDepth, totalDuration, this.duration, sb);
    }
  }

  private String getIndent(int depth) {

    return " ".repeat(depth);
  }

  @Override
  public String toString() {

    StringBuilder sb = new StringBuilder(4096);
    append(0, this.duration, this.duration, sb);
    return sb.toString();
  }
}

1	package com.devonfw.tools.ide.step;
2
3	import java.time.Duration;
4	import java.util.ArrayList;
5	import java.util.Arrays;
6	import java.util.List;
7
8	import org.slf4j.Logger;
9	import org.slf4j.LoggerFactory;
10	import org.slf4j.event.Level;
11
12	import com.devonfw.tools.ide.context.AbstractIdeContext;
13	import com.devonfw.tools.ide.context.IdeContext;
14	import com.devonfw.tools.ide.log.IdeLogLevel;
15
16	/**
17	* Regular implementation of {@link Step}.
18	*/
19	public final class StepImpl implements Step {
20
21	private static final Logger LOG = LoggerFactory.getLogger(StepImpl.class);	4✔
22
23	private final AbstractIdeContext context;
24
25	private final StepImpl parent;
26
27	private final String name;
28
29	private final Object[] params;
30
31	private final List<StepImpl> children;
32
33	private final long start;
34
35	private final boolean silent;
36
37	private Boolean success;
38
39	private String errorMessage;
40
41	private long duration;
42
43	/**
44	* Creates and starts a new {@link StepImpl}.
45	*
46	* @param context the {@link IdeContext}.
47	* @param parent the {@link #getParent() parent step}.
48	* @param name the {@link #getName() step name}.
49	* @param silent the {@link #isSilent() silent flag}.
50	* @param params the parameters. Should have reasonable {@link Object#toString() string representations}.
51	*/
52	public StepImpl(AbstractIdeContext context, StepImpl parent, String name, boolean silent, Object... params) {
53
54	super();	2✔
55	this.context = context;	3✔
56	this.parent = parent;	3✔
57	this.name = name;	3✔
58	this.params = params;	3✔
59	this.silent = silent;	3✔
60	this.children = new ArrayList<>();	5✔
61	this.start = System.currentTimeMillis();	3✔
62	if (parent != null) {	2✔
63	parent.children.add(this);	5✔
64	}
65	if (params.length == 0) {	3✔
66	LOG.trace("Starting step {}...", name);	5✔
67	} else {
68	LOG.trace("Starting step {} with params {}...", name, Arrays.toString(params));	6✔
69	}
70	if (!this.silent) {	3✔
71	LOG.info(IdeLogLevel.STEP.getSlf4jMarker(), "Start: {}", name);	6✔
72	}
73	}	1✔
74
75	@Override
76	public StepImpl getParent() {
77
78	return this.parent;	3✔
79	}
80
81	@Override
82	public String getName() {
83
84	return this.name;	×
85	}
86
87	@Override
88	public Object getParameter(int i) {
89
90	if ((i < 0) \|\| (i >= this.params.length)) {	7!
91	return null;	2✔
92	}
93	return this.params[i];	5✔
94	}
95
96	@Override
97	public int getParameterCount() {
98
99	return this.params.length;	4✔
100	}
101
102	@Override
103	public boolean isSilent() {
104
105	return this.silent;	×
106	}
107
108	@Override
109	public long getDuration() {
110
111	return this.duration;	3✔
112	}
113
114	@Override
115	public Boolean getSuccess() {
116
117	return this.success;	3✔
118	}
119
120	@Override
121	public void success(String message, Object... args) {
122
123	end(Boolean.TRUE, null, false, message, args);	7✔
124	}	1✔
125
126	@Override
127	public void error(Throwable error, boolean suppress, String message, Object... args) {
128
129	end(Boolean.FALSE, error, suppress, message, args);	7✔
130	}	1✔
131
132	@Override
133	public void close() {
134
135	end(null, null, false, null, null);	7✔
136	}	1✔
137
138	private void end(Boolean newSuccess, Throwable error, boolean suppress, String message, Object[] args) {
139
140	boolean firstCallOfEnd = (this.success == null);	7✔
141	if (!firstCallOfEnd) {	2✔
142	assert (this.duration > 0);	6!
143	if ((newSuccess != null) && (newSuccess != this.success)) {	6!
144	LOG.warn("Step '{}' already ended with {} and now ended again with {}.", this.name, this.success, newSuccess);	20✔
145	} else {
146	return;	1✔
147	}
148	}
149	long delay = System.currentTimeMillis() - this.start;	5✔
150	if (delay == 0) {	4✔
151	delay = 1;	2✔
152	}
153	if (newSuccess == null) {	2!
154	newSuccess = Boolean.FALSE;	×
155	}
156	if (!Boolean.FALSE.equals(this.success)) { // never allow a failed step to change to success	5✔
157	this.duration = delay;	3✔
158	this.success = newSuccess;	3✔
159	}
160	if (newSuccess.booleanValue()) {	3✔
161	assert (error == null);	3!
162	if (message != null) {	2✔
163	LOG.info(IdeLogLevel.SUCCESS.getSlf4jMarker(), message, args);	7✔
164	} else if (!this.silent) {	3✔
165	LOG.info(IdeLogLevel.SUCCESS.getSlf4jMarker(), "Successfully ended step '{}'.", this.name);	7✔
166	}
167	LOG.debug("Step '{}' ended successfully.", this.name);	6✔
168	} else {
169	Level level;
170	if ((message != null) \|\| (error != null)) {	4!
171	if (suppress) {	2✔
172	if (error != null) {	2!
173	this.errorMessage = error.toString();	5✔
174	} else {
175	this.errorMessage = message;	×
176	}
177	level = Level.DEBUG;	3✔
178	} else {
179	if (message == null) {	2✔
180	message = error.getMessage();	3✔
181	}
182	if (args == null) {	2✔
183	LOG.atError().setCause(error).log(message);	7✔
184	} else {
185	LOG.atError().setCause(error).log(message, args);	7✔
186	}
187	if (error == null) {	2✔
188	level = Level.DEBUG;	3✔
189	} else {
190	level = Level.ERROR;	3✔
191	}
192	}
193	} else {
194	level = Level.INFO;	×
195	}
196	LOG.atLevel(level).log("Step '{}' ended with failure.", this.name);	7✔
197	}
198	if (firstCallOfEnd) {	2✔
199	this.context.endStep(this);	4✔
200	}
201	}	1✔
202
203	/**
204	* Logs the summary of this {@link Step}. Should typically only be called on the top-level {@link Step}.
205	*
206	* @param suppressSuccess - {@code true} to suppress the success message, {@code false} otherwise.
207	*/
208	public void logSummary(boolean suppressSuccess) {
209
210	if (LOG.isTraceEnabled()) {	3!
211	LOG.trace(toString());	4✔
212	}
213	if (this.context.isQuietMode() \|\| (this.children.isEmpty())) {	8!
214	return;	1✔
215	}
216	StepSummary summary = new StepSummary();	×
217	logErrorSummary(0, summary);	×
218	if (summary.getError() == 0) {	×
219	if (!suppressSuccess) {	×
220	LOG.info(IdeLogLevel.SUCCESS.getSlf4jMarker(), "Successfully completed {}", getNameWithParams());	×
221	}
222	} else {
223	LOG.error(summary.toString());	×
224	}
225	}	×
226
227	private void logErrorSummary(int depth, StepSummary summary) {
228
229	boolean failure = isFailure();	×
230	summary.add(failure);	×
231	if (failure) {	×
232	String error = this.errorMessage;	×
233	if (error == null) {	×
234	error = "unexpected error";	×
235	}
236	LOG.error("{}Step '{}' failed: {}", getIndent(depth), getNameWithParams(), error);	×
237	}
238	depth++;	×
239	for (StepImpl child : this.children) {	×
240	child.logErrorSummary(depth, summary);	×
241	}	×
242	}	×
243
244	private String getNameWithParams() {
245
246	if ((this.params == null) \|\| (this.params.length == 0)) {	×
247	return this.name;	×
248	}
249	StringBuilder sb = new StringBuilder(this.name.length() + 3 + this.params.length * 6);	×
250	getNameWithParams(sb);	×
251	return sb.toString();	×
252	}
253
254	private void getNameWithParams(StringBuilder sb) {
255
256	sb.append(this.name);	5✔
257	sb.append(" (");	4✔
258	String seperator = "";	2✔
259	if (this.params != null) {	3!
260	for (Object param : this.params) {	17✔
261	sb.append(seperator);	4✔
262	sb.append(param);	4✔
263	seperator = ",";	2✔
264	}
265	}
266	sb.append(')');	4✔
267	}	1✔
268
269	private void append(int depth, long totalDuration, long parentDuration, StringBuilder sb) {
270
271	// indent
272	sb.append(getIndent(depth));	6✔
273	getNameWithParams(sb);	3✔
274	sb.append(' ');	4✔
275	if (this.success == null) {	3!
276	sb.append("is still running or was not properly ended due to programming error not using finally block ");	×
277	} else {
278	if (this.success.booleanValue()) {	4✔
279	sb.append("succeeded after ");	5✔
280	} else {
281	sb.append("failed after ");	4✔
282	}
283	sb.append(Duration.ofMillis(this.duration));	6✔
284	}
285	if (this.duration < totalDuration) {	5!
286	sb.append(" ");	×
287	double percentageBase = this.duration * 100;	×
288	double totalPercentage = percentageBase / totalDuration;	×
289	sb.append(totalPercentage);	×
290	sb.append("% of total ");	×
291	if (parentDuration < totalDuration) {	×
292	double parentPercentage = percentageBase / parentDuration;	×
293	sb.append(parentPercentage);	×
294	sb.append("% of parent");	×
295	}
296	}
297	sb.append('\n');	4✔
298	int childDepth = depth + 1;	4✔
299	for (StepImpl child : this.children) {	7!
300	child.append(childDepth, totalDuration, this.duration, sb);	×
301	}	×
302	}	1✔
303
304	private String getIndent(int depth) {
305
306	return " ".repeat(depth);	4✔
307	}
308
309	@Override
310	public String toString() {
311
312	StringBuilder sb = new StringBuilder(4096);	5✔
313	append(0, this.duration, this.duration, sb);	8✔
314	return sb.toString();	3✔
315	}
316	}

devonfw / IDEasy / 22284264868

Source File Press 'n' to go to next uncovered line, 'b' for previous

Source File
Press 'n' to go to next uncovered line, 'b' for previous