Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HysrixRequestLog: Missing Events and Time on Timeouts #55

Closed
benjchristensen opened this issue Dec 17, 2012 · 2 comments
Closed

HysrixRequestLog: Missing Events and Time on Timeouts #55

benjchristensen opened this issue Dec 17, 2012 · 2 comments
Labels
bug

Comments

@benjchristensen
Copy link
Contributor

It appears that the request log is showing the time a fallback took instead of execution when a TIMEOUT occurs followed by FALLBACK.

It should show the execution time.

Should we show both the execution and fallback somehow?

Here is an example request log with a timeout occurring on a request with a log of executions during a latency monkey simulation:

DeviceTypeServiceGetType[SUCCESS][0ms], IdentityCookieAuth[SUCCESS][0ms], SubscriberGetAccount[SUCCESS][5ms], ABCallServiceInternal[SUCCESS][87ms]x2, ABTestGetAllocationMap[SUCCESS][1ms]x2, PlaylistGet[SUCCESS][11ms], ViewingHistoryGetViewingHistory[SUCCESS][29ms], ABTestGetAllocationMap[SUCCESS, RESPONSE_FROM_CACHE][0ms]x306, PlaylistGet[Executed][0ms]x5, ViewingHistoryGetViewingHistory[Executed][0ms]x5, PlaylistGet[SUCCESS, RESPONSE_FROM_CACHE][0ms]x10, NDCMapReadCassandraPersister[SUCCESS][83ms]x2, NDCMapReadEVCachePersister[SUCCESS][79ms]x2, NDCMapReadBulkCassandraPersister[SUCCESS][29ms], NDCMapReadBulkEVCachePersister[SUCCESS][19ms], MapGetLists[TIMEOUT, FALLBACK_SUCCESS][0ms], MapGetLists[TIMEOUT, FALLBACK_SUCCESS, RESPONSE_FROM_CACHE][0ms]x5, VideoMetadataGetEpisodes[SUCCESS][0ms]x28, VideoMetadataGetEpisodes[Executed][0ms]x32, SubscriberGetAccount[SUCCESS, RESPONSE_FROM_CACHE][0ms]x260, QTGetQTVGenres[SUCCESS][0ms]x13, CinematchGetMovieRatings[SUCCESS][7ms], VideoMetadataGetEpisodes[SUCCESS, RESPONSE_FROM_CACHE][0ms]x10, ABTestGetAllocationsCommand[SUCCESS][78ms], VideoHistoryGetBookmarks[SUCCESS, COLLAPSED][179ms]x13, CinematchGetMovieRatings[SUCCESS, RESPONSE_FROM_CACHE][0ms]x18, CinematchGetPredictions[SUCCESS, COLLAPSED][95ms]x17, VideoMetadataGetEpisode[SUCCESS][0ms]x6, QTGetQTVGenres[SUCCESS, RESPONSE_FROM_CACHE][0ms]x6, MapODPGetConfig[TIMEOUT][0ms]
@benjchristensen
Copy link
Contributor Author

Updated issue title to match new information.

It's not just time, it's events as well. Here is an example "ABCallServiceInternal[Executed][0ms]" that displays "Executed" which is placed when it has no events recorded.

@benjchristensen
Copy link
Contributor Author

Fixed in 1.1.7

Examples:

CryptexDecipher[TIMEOUT][1501ms]
CinematchGetPredictions[TIMEOUT, FALLBACK_SUCCESS, COLLAPSED][1059ms]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@benjchristensen