1414
1515package software .amazon .lambda .powertools .testutils .tracing ;
1616
17+ import java .time .Duration ;
1718import java .time .Instant ;
1819import java .time .temporal .ChronoUnit ;
1920import java .util .Arrays ;
2728
2829import com .fasterxml .jackson .core .JsonProcessingException ;
2930import com .fasterxml .jackson .databind .DeserializationFeature ;
31+ import com .fasterxml .jackson .databind .MapperFeature ;
3032import com .fasterxml .jackson .databind .ObjectMapper ;
33+ import com .fasterxml .jackson .databind .json .JsonMapper ;
3134
35+ import io .github .resilience4j .retry .RetryConfig ;
3236import software .amazon .awssdk .http .SdkHttpClient ;
3337import software .amazon .awssdk .http .urlconnection .UrlConnectionHttpClient ;
3438import software .amazon .awssdk .regions .Region ;
4650 * Class in charge of retrieving the actual traces of a Lambda execution on X-Ray
4751 */
4852public class TraceFetcher {
49-
50- private static final ObjectMapper MAPPER = new ObjectMapper ()
51- .configure (DeserializationFeature .FAIL_ON_UNKNOWN_PROPERTIES , false );
53+ private static final ObjectMapper MAPPER = JsonMapper .builder ()
54+ .disable (MapperFeature .REQUIRE_HANDLERS_FOR_JAVA8_TIMES )
55+ .configure (DeserializationFeature .FAIL_ON_UNKNOWN_PROPERTIES , false )
56+ .build ();
5257 private static final Logger LOG = LoggerFactory .getLogger (TraceFetcher .class );
5358 private static final SdkHttpClient httpClient = UrlConnectionHttpClient .builder ().build ();
5459 private static final Region region = Region .of (System .getProperty ("AWS_DEFAULT_REGION" , "eu-west-1" ));
@@ -90,7 +95,12 @@ public Trace fetchTrace() {
9095 return getTrace (traceIds );
9196 };
9297
93- return RetryUtils .withRetry (supplier , "trace-fetcher" , TraceNotFoundException .class ).get ();
98+ RetryConfig customConfig = RetryConfig .custom ()
99+ .maxAttempts (120 ) // 120 attempts over 10 minutes
100+ .waitDuration (Duration .ofSeconds (5 )) // 5 seconds between attempts
101+ .build ();
102+
103+ return RetryUtils .withRetry (supplier , "trace-fetcher" , customConfig , TraceNotFoundException .class ).get ();
94104 }
95105
96106 /**
@@ -104,26 +114,41 @@ private Trace getTrace(List<String> traceIds) {
104114 .traceIds (traceIds )
105115 .build ());
106116 if (!tracesResponse .hasTraces ()) {
107- throw new TraceNotFoundException ("No trace found" );
117+ throw new TraceNotFoundException (String . format ( "No trace found for traceIds %s" , traceIds ) );
108118 }
119+
109120 Trace traceRes = new Trace ();
110121 tracesResponse .traces ().forEach (trace -> {
111122 if (trace .hasSegments ()) {
112123 trace .segments ().forEach (segment -> {
113124 try {
114125 SegmentDocument document = MAPPER .readValue (segment .document (), SegmentDocument .class );
115126 if ("AWS::Lambda::Function" .equals (document .getOrigin ()) && document .hasSubsegments ()) {
116- getNestedSubSegments (document .getSubsegments (), traceRes ,
117- Collections .emptyList ());
127+ LOG .debug ("Populating subsegments for document {}" , MAPPER .writeValueAsString (document ));
128+ getNestedSubSegments (document .getSubsegments (), traceRes , Collections .emptyList ());
129+ // If only the default (excluded) subsegments were populated we need to keep retrying for
130+ // our custom subsegments. They might appear later.
131+ if (traceRes .getSubsegments ().isEmpty ()) {
132+ throw new TraceNotFoundException (
133+ "Found AWS::Lambda::Function SegmentDocument with no non-excluded subsegments." );
134+ }
135+ } else if ("AWS::Lambda::Function" .equals (document .getOrigin ())) {
136+ LOG .debug (
137+ "Found AWS::Lambda::Function SegmentDocument with no subsegments. Retrying {}" ,
138+ MAPPER .writeValueAsString (document ));
139+ throw new TraceNotFoundException (
140+ "Found AWS::Lambda::Function SegmentDocument with no subsegments." );
118141 }
119-
120142 } catch (JsonProcessingException e ) {
121143 LOG .error ("Failed to parse segment document: " + e .getMessage ());
122144 throw new RuntimeException (e );
123145 }
124146 });
147+ } else {
148+ throw new TraceNotFoundException (String .format ("No segments found in trace %s" , trace .id ()));
125149 }
126150 });
151+
127152 return traceRes ;
128153 }
129154
@@ -149,21 +174,30 @@ private void getNestedSubSegments(List<SubSegment> subsegments, Trace traceRes,
149174 * @return a list of trace ids
150175 */
151176 private List <String > getTraceIds () {
177+ LOG .debug ("Searching for traces from {} to {} with filter: {}" , start , end , filterExpression );
152178 GetTraceSummariesResponse traceSummaries = xray .getTraceSummaries (GetTraceSummariesRequest .builder ()
153179 .startTime (start )
154180 .endTime (end )
155- .timeRangeType (TimeRangeType .EVENT )
181+ .timeRangeType (TimeRangeType .TRACE_ID )
156182 .sampling (false )
157183 .filterExpression (filterExpression )
158184 .build ());
185+
186+ LOG .debug ("Found {} trace summaries" ,
187+ traceSummaries .hasTraceSummaries () ? traceSummaries .traceSummaries ().size () : 0 );
188+
159189 if (!traceSummaries .hasTraceSummaries ()) {
160- throw new TraceNotFoundException ("No trace id found" );
190+ throw new TraceNotFoundException (String .format ("No trace id found for filter '%s' between %s and %s" ,
191+ filterExpression , start , end ));
161192 }
162193 List <String > traceIds = traceSummaries .traceSummaries ().stream ().map (TraceSummary ::id )
163194 .collect (Collectors .toList ());
164195 if (traceIds .isEmpty ()) {
165- throw new TraceNotFoundException ("No trace id found" );
196+ throw new TraceNotFoundException (
197+ String .format ("Empty trace summary found for filter '%s' between %s and %s" ,
198+ filterExpression , start , end ));
166199 }
200+ LOG .debug ("Found trace IDs: {}" , traceIds );
167201 return traceIds ;
168202 }
169203
@@ -183,9 +217,13 @@ public TraceFetcher build() {
183217 if (end == null ) {
184218 end = start .plus (1 , ChronoUnit .MINUTES );
185219 }
186- LOG .debug ("Looking for traces from {} to {} with filter {} and excluded segments {}" , start , end ,
187- filterExpression , excludedSegments );
188- return new TraceFetcher (start , end , filterExpression , excludedSegments );
220+ // Expand search window by 1 minute on each side to account for timing imprecisions
221+ Instant expandedStart = start .minus (1 , ChronoUnit .MINUTES );
222+ Instant expandedEnd = end .plus (1 , ChronoUnit .MINUTES );
223+ LOG .debug (
224+ "Looking for traces from {} to {} (expanded from {} to {}) with filter {} and excluded segments {}" ,
225+ expandedStart , expandedEnd , start , end , filterExpression , excludedSegments );
226+ return new TraceFetcher (expandedStart , expandedEnd , filterExpression , excludedSegments );
189227 }
190228
191229 public Builder start (Instant start ) {
0 commit comments