Skip to content

Commit 2d5aa06

Browse files
committed
Fix #34869: get logs if container fails to startup
1 parent ab67c02 commit 2d5aa06

7 files changed

Lines changed: 99 additions & 22 deletions

File tree

src/main/java/eu/openanalytics/containerproxy/backend/AbstractContainerBackend.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -152,7 +152,7 @@ public void stopProxy(Proxy proxy) throws ContainerProxyException {
152152
protected abstract void doStopProxy(Proxy proxy) throws Exception;
153153

154154
@Override
155-
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy) {
155+
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy, boolean follow) {
156156
// Default: do not support output attaching.
157157
return null;
158158
}

src/main/java/eu/openanalytics/containerproxy/backend/IContainerBackend.java

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
import eu.openanalytics.containerproxy.model.runtime.ProxyStartupLog;
2929
import eu.openanalytics.containerproxy.model.runtime.ProxyStatus;
3030
import eu.openanalytics.containerproxy.model.spec.ProxySpec;
31+
import org.apache.commons.lang3.tuple.Pair;
3132
import org.springframework.security.core.Authentication;
3233

3334
import java.io.OutputStream;
@@ -78,7 +79,22 @@ default Proxy resumeProxy(Authentication user, Proxy proxy, ProxySpec proxySpec)
7879
* @return A function that will attach the output, or null if this backend does
7980
* not support output attaching.
8081
*/
81-
BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy);
82+
default BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy) {
83+
return getOutputAttacher(proxy, true);
84+
}
85+
86+
/**
87+
* Get a function that will forward the standard output and standard error of
88+
* the given proxy's containers to two output streams.
89+
*
90+
* If follow is false the function does not follow the logs until the container stops.
91+
*
92+
* @param proxy The proxy whose container output should be attached to the output streams.
93+
* @param follow Whether to follow logs until the container stops.
94+
* @return A function that will attach the output, or null if this backend does
95+
* not support output attaching.
96+
*/
97+
BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy, boolean follow);
8298

8399
/**
84100
* Scans for running/existing apps that need to be recovered.
@@ -115,4 +131,5 @@ default Proxy addRuntimeValuesAfterSpel(Authentication user, ProxySpec spec, Pro
115131
* @return whether the proxy is healthy
116132
*/
117133
boolean isProxyHealthy(Proxy proxy);
134+
118135
}

src/main/java/eu/openanalytics/containerproxy/backend/docker/DockerEngineBackend.java

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -328,13 +328,18 @@ public boolean isProxyHealthy(Proxy proxy) {
328328
}
329329

330330
@Override
331-
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy) {
331+
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy, boolean follow) {
332332
Container c = getPrimaryContainer(proxy);
333333
if (c == null) return null;
334334

335335
return (stdOut, stdErr) -> {
336336
try {
337-
LogStream logStream = dockerClient.logs(c.getId(), DockerClient.LogsParam.follow(), DockerClient.LogsParam.stdout(), DockerClient.LogsParam.stderr());
337+
LogStream logStream;
338+
if (follow) {
339+
logStream = dockerClient.logs(c.getId(), DockerClient.LogsParam.follow(), DockerClient.LogsParam.stdout(), DockerClient.LogsParam.stderr());
340+
} else {
341+
logStream = dockerClient.logs(c.getId(), DockerClient.LogsParam.stdout(), DockerClient.LogsParam.stderr());
342+
}
338343
logStream.attach(stdOut, stdErr);
339344
} catch (ClosedChannelException ignored) {
340345
} catch (IOException | InterruptedException | DockerException e) {

src/main/java/eu/openanalytics/containerproxy/backend/docker/DockerSwarmBackend.java

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -391,14 +391,19 @@ public boolean isProxyHealthy(Proxy proxy) {
391391
}
392392

393393
@Override
394-
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy) {
394+
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy, boolean follow) {
395395
Container container = getPrimaryContainer(proxy);
396396
if (container == null) return null;
397397
BackendContainerName serviceId = container.getRuntimeObjectOrNull(BackendContainerNameKey.inst);
398398

399399
return (stdOut, stdErr) -> {
400400
try {
401-
LogStream logStream = dockerClient.serviceLogs(serviceId.getName(), DockerClient.LogsParam.follow(), DockerClient.LogsParam.stdout(), DockerClient.LogsParam.stderr());
401+
LogStream logStream;
402+
if (follow) {
403+
logStream = dockerClient.serviceLogs(serviceId.getName(), DockerClient.LogsParam.follow(), DockerClient.LogsParam.stdout(), DockerClient.LogsParam.stderr());
404+
} else {
405+
logStream = dockerClient.serviceLogs(serviceId.getName(), DockerClient.LogsParam.stdout(), DockerClient.LogsParam.stderr());
406+
}
402407
logStream.attach(stdOut, stdErr);
403408
} catch (ClosedChannelException ignored) {
404409
} catch (IOException | InterruptedException | DockerException e) {

src/main/java/eu/openanalytics/containerproxy/backend/kubernetes/KubernetesBackend.java

Lines changed: 17 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -90,7 +90,7 @@
9090
import io.fabric8.kubernetes.client.dsl.base.PatchType;
9191
import io.fabric8.kubernetes.client.readiness.Readiness;
9292
import io.fabric8.kubernetes.client.utils.Serialization;
93-
import org.apache.commons.compress.utils.IOUtils;
93+
import org.apache.commons.io.IOUtils;
9494
import org.apache.commons.lang3.StringUtils;
9595
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
9696
import org.springframework.security.core.Authentication;
@@ -101,6 +101,7 @@
101101
import javax.json.JsonPatch;
102102
import java.io.ByteArrayInputStream;
103103
import java.io.IOException;
104+
import java.io.InputStream;
104105
import java.io.OutputStream;
105106
import java.net.URI;
106107
import java.nio.channels.ClosedChannelException;
@@ -695,17 +696,23 @@ private boolean canAccessLogs(Proxy proxy, BackendContainerName pod) {
695696
}
696697

697698
@Override
698-
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy) {
699+
public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy, boolean follow) {
699700
if (proxy.getContainers().isEmpty()) return null;
700701
return (stdOut, stdErr) -> {
701702
LogWatch watcher = null;
703+
InputStream inputStream = null;
702704
try {
703705
Container container = proxy.getContainers().get(0);
704706
Optional<BackendContainerName> pod = getPodInfo(container);
705707
if (pod.isPresent()) {
706708
if (canAccessLogs(proxy, pod.get())) {
707-
watcher = kubeClient.pods().inNamespace(pod.get().getNamespace()).withName(pod.get().getName()).watchLog();
708-
IOUtils.copy(watcher.getOutput(), stdOut);
709+
if (follow) {
710+
watcher = kubeClient.pods().inNamespace(pod.get().getNamespace()).withName(pod.get().getName()).watchLog();
711+
IOUtils.copy(watcher.getOutput(), stdOut);
712+
} else {
713+
inputStream = kubeClient.pods().inNamespace(pod.get().getNamespace()).withName(pod.get().getName()).getLogInputStream();
714+
IOUtils.copy(inputStream, stdOut);
715+
}
709716
}
710717
} else {
711718
slog.warn(proxy, "Error while attaching to container output: pod info not found");
@@ -717,6 +724,12 @@ public BiConsumer<OutputStream, OutputStream> getOutputAttacher(Proxy proxy) {
717724
if (watcher != null) {
718725
watcher.close();
719726
}
727+
if (inputStream != null) {
728+
try {
729+
inputStream.close();
730+
} catch (IOException ignored) {
731+
}
732+
}
720733
}
721734
};
722735
}

src/main/java/eu/openanalytics/containerproxy/service/LogService.java

Lines changed: 33 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -33,8 +33,8 @@
3333
import eu.openanalytics.containerproxy.model.store.IProxyStore;
3434
import eu.openanalytics.containerproxy.service.leader.ILeaderService;
3535
import eu.openanalytics.containerproxy.util.ProxyHashMap;
36-
import org.apache.logging.log4j.LogManager;
37-
import org.apache.logging.log4j.Logger;
36+
import org.slf4j.Logger;
37+
import org.slf4j.LoggerFactory;
3838
import org.springframework.context.event.EventListener;
3939
import org.springframework.integration.leader.event.OnGrantedEvent;
4040
import org.springframework.integration.leader.event.OnRevokedEvent;
@@ -55,7 +55,9 @@
5555
@Service
5656
public class LogService {
5757

58-
private final Logger log = LogManager.getLogger(LogService.class);
58+
private final Logger log = LoggerFactory.getLogger(LogService.class);
59+
private final StructuredLogger slog = new StructuredLogger(log);
60+
5961
@Inject
6062
ILogStorage logStorage;
6163
@Inject
@@ -98,7 +100,7 @@ public LogPaths getLogs(Proxy proxy) {
98100
try {
99101
return logStorage.getLogs(proxy);
100102
} catch (IOException e) {
101-
log.error("Failed to locate logs for proxy " + proxy.getId(), e);
103+
slog.error(proxy, e, "Failed to locate logs for proxy " + proxy.getId());
102104
}
103105

104106
return null;
@@ -148,6 +150,24 @@ public void onProxyPaused(ProxyPauseEvent event) {
148150
detach(proxy);
149151
}
150152

153+
public void onProxyStartFailed(Proxy proxy) throws IOException {
154+
if (!isLoggingEnabled() || !iLeaderService.isLeader()) return;
155+
LogStreams streams = logStorage.createOutputStreams(proxy);
156+
if (streams == null) {
157+
slog.warn(proxy, "Failed to attach logging of proxy: no output streams defined");
158+
return;
159+
}
160+
proxyStreams.put(proxy.getId(), streams);
161+
BiConsumer<OutputStream, OutputStream> logs = backend.getOutputAttacher(proxy, false);
162+
if (logs == null) {
163+
return;
164+
}
165+
logs.accept(streams.getStdout(), streams.getStderr());
166+
streams.getStdout().close();
167+
streams.getStderr().close();
168+
}
169+
170+
151171
@EventListener(OnGrantedEvent.class)
152172
public void onLeaderGranted() {
153173
startService();
@@ -166,7 +186,7 @@ private synchronized void startService() {
166186
if (executor == null) {
167187
executor = Executors.newCachedThreadPool();
168188
}
169-
log.info("Container logging enabled. Log files will be saved to " + logStorage.getStorageLocation());
189+
log.info("Container logging enabled. Log files will be saved to {}", logStorage.getStorageLocation());
170190
// attach existing proxies
171191
for (Proxy proxy : proxyStore.getAllProxies()) {
172192
attachToOutput(proxy);
@@ -194,30 +214,32 @@ public void attachToOutput(Proxy proxy) {
194214
return;
195215
}
196216
if (!iLeaderService.isLeader()) {
197-
log.warn("Cannot log proxy output: not the leader.");
217+
slog.warn(proxy, "Cannot log proxy output: not the leader.");
198218
return;
199219
}
200220
BiConsumer<OutputStream, OutputStream> outputAttacher = backend.getOutputAttacher(proxy);
201221
if (outputAttacher == null) {
202-
log.warn("Cannot log proxy output: " + backend.getClass() + " does not support output attaching.");
222+
slog.warn(proxy, "Cannot log proxy output: " + backend.getClass() + " does not support output attaching.");
203223
return;
204224
}
205225

206226
executor.submit(() -> {
207227
try {
208228
LogStreams streams = logStorage.createOutputStreams(proxy);
209229
if (streams == null) {
210-
log.error("Failed to attach logging of proxy " + proxy.getId() + ": no output streams defined");
230+
slog.warn(proxy, "Failed to attach logging of proxy: no output streams defined");
211231
return;
212232
}
213233
proxyStreams.put(proxy.getId(), streams);
214234
if (log.isDebugEnabled()) log.debug("Container logging started for proxy " + proxy.getId());
215235
// Note that this call will block until the container is stopped.
216236
outputAttacher.accept(streams.getStdout(), streams.getStderr());
217237
} catch (Exception e) {
218-
log.error("Failed to attach logging of proxy " + proxy.getId(), e);
238+
slog.error(proxy,e, "Failed to attach logging of proxy " + proxy.getId());
239+
}
240+
if (log.isDebugEnabled()) {
241+
slog.debug(proxy, "Container logging ended for proxy ");
219242
}
220-
if (log.isDebugEnabled()) log.debug("Container logging ended for proxy " + proxy.getId());
221243
});
222244
}
223245

@@ -227,7 +249,7 @@ public void detach(Proxy proxy) {
227249
}
228250
LogStreams streams = proxyStreams.get(proxy.getId());
229251
if (streams == null) {
230-
log.warn("Cannot detach container logging: streams not found");
252+
slog.warn(proxy, "Cannot detach container logging: streams not found");
231253
return;
232254
}
233255
detach(proxy.getId(), streams);

src/main/java/eu/openanalytics/containerproxy/service/ProxyService.java

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -109,6 +109,8 @@ public class ProxyService {
109109
private RuntimeValueService runtimeValueService;
110110
@Inject
111111
private SpecExpressionResolver expressionResolver;
112+
@Inject
113+
private LogService logService;
112114
private boolean stopAppsOnShutdown;
113115
private Pair<String, Instant> lastStop = null;
114116
private int requestTimeout;
@@ -427,7 +429,6 @@ public boolean isProxyHealthy(Proxy proxy) {
427429
if (!proxyDispatcherService.getDispatcher(proxy.getSpecId()).isProxyHealthy(proxy)) {
428430
return false;
429431
}
430-
int timeoutMs = Integer.parseInt(environment.getProperty("proxy.container-wait-timeout", "5000"));
431432
if (proxy.getTargets().isEmpty()) {
432433
slog.info(proxy, "Proxy failed: no targets available");
433434
return false;
@@ -514,6 +515,13 @@ private Proxy startOrResumeProxy(Authentication user, Proxy proxy, ProxyStartupL
514515
}
515516
} catch (ProxyFailedToStartException t) {
516517
slog.warn(t.getProxy(), t, "Proxy failed to start");
518+
try {
519+
logService.onProxyStartFailed(t.getProxy());
520+
} catch (Throwable t2) {
521+
// log error, but ignore it otherwise
522+
// most important is that we remove the proxy from memory
523+
slog.warn(t.getProxy(), t, "Error while collecting logs of failed proxy");
524+
}
517525
try {
518526
proxyDispatcherService.getDispatcher(spec.getId()).stopProxy(t.getProxy());
519527
} catch (Throwable t2) {
@@ -536,6 +544,13 @@ private Proxy startOrResumeProxy(Authentication user, Proxy proxy, ProxyStartupL
536544
}
537545

538546
if (!testStrategy.testProxy(proxy)) {
547+
try {
548+
logService.onProxyStartFailed(proxy);
549+
} catch (Throwable t2) {
550+
// log error, but ignore it otherwise
551+
// most important is that we remove the proxy from memory
552+
slog.warn(proxy, t2, "Error while collecting logs of failed proxy");
553+
}
539554
try {
540555
proxyDispatcherService.getDispatcher(spec.getId()).stopProxy(proxy);
541556
} catch (Throwable t) {

0 commit comments

Comments
 (0)