Skip to content

Commit 8de8b47

Browse files
amvanbarenamvanbaren
authored
Merge pull request #1096 from amvanbaren/debug-azure-useragent
Debug AzureDownloadCount userAgentHeader
2 parents c3b160e + ee65e37 commit 8de8b47

File tree

1 file changed

+122
-130
lines changed

1 file changed

+122
-130
lines changed

‎server/src/main/java/org/eclipse/openvsx/storage/AzureDownloadCountService.java‎

Lines changed: 122 additions & 130 deletions
Original file line numberDiff line numberDiff line change
@@ -91,15 +91,13 @@ public AzureDownloadCountService(
9191
* Indicates whether the download service is enabled by application config.
9292
*/
9393
public boolean isEnabled() {
94-
return Observation.createNotStarted("AzureDownloadCountService#isEnabled", observations).observe(() -> {
95-
var logsEnabled = !StringUtils.isEmpty(logsServiceEndpoint);
96-
var storageEnabled = !StringUtils.isEmpty(storageServiceEndpoint);
97-
if (logsEnabled && !storageEnabled) {
98-
logger.warn("The ovsx.storage.azure.service-endpoint value must be set to enable AzureDownloadCountService");
99-
}
94+
var logsEnabled = !StringUtils.isEmpty(logsServiceEndpoint);
95+
var storageEnabled = !StringUtils.isEmpty(storageServiceEndpoint);
96+
if (logsEnabled && !storageEnabled) {
97+
logger.warn("The ovsx.storage.azure.service-endpoint value must be set to enable AzureDownloadCountService");
98+
}
10099

101-
return logsEnabled && storageEnabled;
102-
});
100+
return logsEnabled && storageEnabled;
103101
}
104102

105103
/**
@@ -108,66 +106,64 @@ public boolean isEnabled() {
108106
@Job(name = "Update Download Counts", retries = 0)
109107
@Recurring(id = "update-download-counts", cron = "0 5 * * * *", zoneId = "UTC")
110108
public void updateDownloadCounts() {
111-
Observation.createNotStarted("AzureDownloadCountService#updateDownloadCounts", observations).observe(() -> {
112-
if (!isEnabled()) {
113-
return;
114-
}
109+
if (!isEnabled()) {
110+
return;
111+
}
115112

116-
logger.info(">> updateDownloadCounts");
117-
var maxExecutionTime = LocalDateTime.now().withMinute(55);
118-
var blobs = listBlobs();
119-
var iterableByPage = blobs.iterableByPage();
120-
121-
var stopWatch = new StopWatch();
122-
while (iterableByPage != null) {
123-
PagedResponse<BlobItem> response = null;
124-
var iterator = iterableByPage.iterator();
125-
if (iterator.hasNext()) {
126-
response = iterator.next();
127-
var blobNames = getBlobNames(response.getValue());
128-
var processedItems = processor.processedItems(blobNames);
129-
processedItems.forEach(this::deleteBlob);
130-
blobNames.removeAll(processedItems);
131-
for (var name : blobNames) {
132-
if (LocalDateTime.now().isAfter(maxExecutionTime)) {
133-
var nextJobRunTime = LocalDateTime.now().plusHours(1).withMinute(5);
134-
logger.info("Failed to process all download counts within timeslot, next job run is at {}", nextJobRunTime);
135-
logger.info("<< updateDownloadCounts");
136-
return;
137-
}
113+
logger.info(">> updateDownloadCounts");
114+
var maxExecutionTime = LocalDateTime.now().withMinute(55);
115+
var blobs = listBlobs();
116+
var iterableByPage = blobs.iterableByPage();
117+
118+
var stopWatch = new StopWatch();
119+
while (iterableByPage != null) {
120+
PagedResponse<BlobItem> response = null;
121+
var iterator = iterableByPage.iterator();
122+
if (iterator.hasNext()) {
123+
response = iterator.next();
124+
var blobNames = getBlobNames(response.getValue());
125+
var processedItems = processor.processedItems(blobNames);
126+
processedItems.forEach(this::deleteBlob);
127+
blobNames.removeAll(processedItems);
128+
for (var name : blobNames) {
129+
if (LocalDateTime.now().isAfter(maxExecutionTime)) {
130+
var nextJobRunTime = LocalDateTime.now().plusHours(1).withMinute(5);
131+
logger.info("Failed to process all download counts within timeslot, next job run is at {}", nextJobRunTime);
132+
logger.info("<< updateDownloadCounts");
133+
return;
134+
}
138135

139-
var processedOn = LocalDateTime.now();
140-
var success = false;
141-
stopWatch.start();
142-
try {
143-
var files = processBlobItem(name);
144-
if (!files.isEmpty()) {
145-
var extensionDownloads = processor.processDownloadCounts(files);
146-
var updatedExtensions = processor.increaseDownloadCounts(extensionDownloads);
147-
processor.evictCaches(updatedExtensions);
148-
processor.updateSearchEntries(updatedExtensions);
149-
}
150-
151-
success = true;
152-
} catch (Exception e) {
153-
logger.error("Failed to process BlobItem: " + name, e);
136+
var processedOn = LocalDateTime.now();
137+
var success = false;
138+
stopWatch.start();
139+
try {
140+
var files = processBlobItem(name);
141+
if (!files.isEmpty()) {
142+
var extensionDownloads = processor.processDownloadCounts(files);
143+
var updatedExtensions = processor.increaseDownloadCounts(extensionDownloads);
144+
processor.evictCaches(updatedExtensions);
145+
processor.updateSearchEntries(updatedExtensions);
154146
}
155147

156-
stopWatch.stop();
157-
var executionTime = (int) stopWatch.getLastTaskTimeMillis();
158-
processor.persistProcessedItem(name, processedOn, executionTime, success);
159-
if(success) {
160-
deleteBlob(name);
161-
}
148+
success = true;
149+
} catch (Exception e) {
150+
logger.error("Failed to process BlobItem: " + name, e);
162151
}
163-
}
164152

165-
var continuationToken = response != null ? response.getContinuationToken() : "";
166-
iterableByPage = !StringUtils.isEmpty(continuationToken) ? blobs.iterableByPage(continuationToken) : null;
153+
stopWatch.stop();
154+
var executionTime = (int) stopWatch.getLastTaskTimeMillis();
155+
processor.persistProcessedItem(name, processedOn, executionTime, success);
156+
if(success) {
157+
deleteBlob(name);
158+
}
159+
}
167160
}
168161

169-
logger.info("<< updateDownloadCounts");
170-
});
162+
var continuationToken = response != null ? response.getContinuationToken() : "";
163+
iterableByPage = !StringUtils.isEmpty(continuationToken) ? blobs.iterableByPage(continuationToken) : null;
164+
}
165+
166+
logger.info("<< updateDownloadCounts");
171167
}
172168

173169
private void deleteBlob(String blobName) {
@@ -183,40 +179,38 @@ private void deleteBlob(String blobName) {
183179
}
184180

185181
private Map<String, Integer> processBlobItem(String blobName) {
186-
return Observation.createNotStarted("AzureDownloadCountService#processBlobItem", observations).observe(() -> {
187-
try (
188-
var downloadsTempFile = downloadBlobItem(blobName);
189-
var reader = Files.newBufferedReader(downloadsTempFile.getPath())
190-
) {
191-
return reader.lines()
192-
.map(line -> {
193-
try {
194-
return getObjectMapper().readTree(line);
195-
} catch (JsonProcessingException e) {
196-
throw new RuntimeException(e);
197-
}
198-
})
199-
.filter(node -> {
200-
return isGetBlobOperation(node)
201-
&& isStatusOk(node)
202-
&& isExtensionPackageUri(node)
203-
&& isNotOpenVSXUserAgent(node);
204-
}).map(node -> {
205-
var uri = node.get("uri").asText();
206-
var pathParams = uri.substring(storageServiceEndpoint.length()).split("/");
207-
return Map.entry(pathParams, node.get("time").asText());
208-
})
209-
.filter(entry -> storageBlobContainer.equals(entry.getKey()[1]))
210-
.map(entry -> {
211-
var pathParams = entry.getKey();
212-
var fileName = UriUtils.decode(pathParams[pathParams.length - 1], StandardCharsets.UTF_8).toUpperCase();
213-
return Map.entry(fileName, 1);
214-
})
215-
.collect(Collectors.groupingBy(Map.Entry::getKey, Collectors.summingInt(Map.Entry::getValue)));
216-
} catch (IOException e) {
217-
throw new RuntimeException(e);
218-
}
219-
});
182+
try (
183+
var downloadsTempFile = downloadBlobItem(blobName);
184+
var reader = Files.newBufferedReader(downloadsTempFile.getPath())
185+
) {
186+
return reader.lines()
187+
.map(line -> {
188+
try {
189+
return getObjectMapper().readTree(line);
190+
} catch (JsonProcessingException e) {
191+
throw new RuntimeException(e);
192+
}
193+
})
194+
.filter(node -> {
195+
return isGetBlobOperation(node)
196+
&& isStatusOk(node)
197+
&& isExtensionPackageUri(node)
198+
&& isNotOpenVSXUserAgent(node);
199+
}).map(node -> {
200+
var uri = node.get("uri").asText();
201+
var pathParams = uri.substring(storageServiceEndpoint.length()).split("/");
202+
return Map.entry(pathParams, node.get("time").asText());
203+
})
204+
.filter(entry -> storageBlobContainer.equals(entry.getKey()[1]))
205+
.map(entry -> {
206+
var pathParams = entry.getKey();
207+
var fileName = UriUtils.decode(pathParams[pathParams.length - 1], StandardCharsets.UTF_8).toUpperCase();
208+
return Map.entry(fileName, 1);
209+
})
210+
.collect(Collectors.groupingBy(Map.Entry::getKey, Collectors.summingInt(Map.Entry::getValue)));
211+
} catch (IOException e) {
212+
throw new RuntimeException(e);
213+
}
220214
}
221215

222216
private boolean isGetBlobOperation(JsonNode node) {
@@ -232,53 +226,51 @@ private boolean isExtensionPackageUri(JsonNode node) {
232226
}
233227

234228
private boolean isNotOpenVSXUserAgent(JsonNode node) {
235-
return !node.get("properties").get("userAgentHeader").asText().equals(AZURE_USER_AGENT);
229+
var userAgentHeader = node.path("properties").path("userAgentHeader").asText();
230+
if(StringUtils.isEmpty(userAgentHeader)) {
231+
try {
232+
logger.info("USER AGENT HEADER IS EMPTY, JSON:\n{}", getObjectMapper().writeValueAsString(node));
233+
} catch (JsonProcessingException e) {
234+
// do nothing, this logger statement is for debugging purposes
235+
}
236+
237+
throw new IllegalArgumentException("Expected node to have userAgentHeader property");
238+
}
239+
240+
return !userAgentHeader.equals(AZURE_USER_AGENT);
236241
}
237242

238243

239-
private TempFile downloadBlobItem(String blobName) /*throws IOException*/ {
240-
return Observation.createNotStarted("AzureDownloadCountService#downloadBlobItem", observations).observe(() -> {
241-
TempFile downloadsTempFile;
242-
try {
243-
downloadsTempFile = new TempFile("azure-downloads-", ".json");
244-
} catch (IOException e) {
245-
// TODO add `throws IOException` to `downloadBlobItem` method signature when reverting Observations
246-
// TODO remove try catch around `downloadsTempFile`
247-
throw new RuntimeException(e);
248-
}
249-
getContainerClient().getBlobClient(blobName).downloadToFile(downloadsTempFile.getPath().toAbsolutePath().toString(), true);
250-
return downloadsTempFile;
251-
});
244+
private TempFile downloadBlobItem(String blobName) throws IOException {
245+
var downloadsTempFile = new TempFile("azure-downloads-", ".json");
246+
getContainerClient().getBlobClient(blobName).downloadToFile(downloadsTempFile.getPath().toAbsolutePath().toString(), true);
247+
return downloadsTempFile;
252248
}
253249

254250
private List<String> getBlobNames(List<BlobItem> items) {
255-
return Observation.createNotStarted("AzureDownloadCountService#getBlobNames", observations).observe(() -> {
256-
var blobNames = new ArrayList<String>();
257-
for (var item : items) {
258-
var name = item.getName();
259-
if (isCorrectName(name)) {
260-
blobNames.add(name);
261-
}
251+
var blobNames = new ArrayList<String>();
252+
for (var item : items) {
253+
var name = item.getName();
254+
if (isCorrectName(name)) {
255+
blobNames.add(name);
262256
}
257+
}
263258

264-
return blobNames;
265-
});
259+
return blobNames;
266260
}
267261

268262
private PagedIterable<BlobItem> listBlobs() {
269-
return Observation.createNotStarted("AzureDownloadCountService#listBlobs", observations).observe(() -> {
270-
var details = new BlobListDetails()
271-
.setRetrieveCopy(false)
272-
.setRetrieveMetadata(false)
273-
.setRetrieveDeletedBlobs(false)
274-
.setRetrieveTags(false)
275-
.setRetrieveSnapshots(false)
276-
.setRetrieveUncommittedBlobs(false)
277-
.setRetrieveVersions(false);
278-
279-
var options = new ListBlobsOptions().setMaxResultsPerPage(100).setDetails(details);
280-
return getContainerClient().listBlobs(options, Duration.ofMinutes(5));
281-
});
263+
var details = new BlobListDetails()
264+
.setRetrieveCopy(false)
265+
.setRetrieveMetadata(false)
266+
.setRetrieveDeletedBlobs(false)
267+
.setRetrieveTags(false)
268+
.setRetrieveSnapshots(false)
269+
.setRetrieveUncommittedBlobs(false)
270+
.setRetrieveVersions(false);
271+
272+
var options = new ListBlobsOptions().setMaxResultsPerPage(100).setDetails(details);
273+
return getContainerClient().listBlobs(options, Duration.ofMinutes(5));
282274
}
283275

284276
private BlobContainerClient getContainerClient() {

0 commit comments

Comments
 (0)