Common Logs Explained
The following are the examples of .Net logs you'll find for some common scenarios
1. Validation Logs
Most of the validation problems are because of the mismatch between market-associated specifiers and which specifiers are expected based on the market description. This is just a log entry; the message is processed and dispatched to the user code normally.
Example
2023-06-07 14:54:46,260 INFO [19] FeedMessageValidator Specifiers check failed. Producer=5, market[id=877], Required:inningnr,total,maxovers, Actual:matchinningnr,maxovers,total,inningnr
2023-06-07 14:54:46,264 WARN [19] OddsFeedSession Live: Problems were detected while validating message=[odds_change ProducerId=5, EventId=sr:match:40481547, GeneratedAt=1686141350193, ReceivedAt=1686142486152, Age=1135959], but the message is still eligible for further processing.
2. FeedExt Raw Data Processing Logs
When subscribing to raw data (feed and API) utilizing FeedExt instead of a normal Feed instance, SDK logs how long it took in user code to process the raw message. Long times could indicate problems in user code and will slow down message processing in the SDK pipeline.
Example
2023-05-16 13:08:59,474 INFO [com:5671)] FeedExt Dispatching raw feed message [prematch]: odds_change for event sr:match:39497539 (173202793) took 1 ms.
3. RabbitMQ Message Logs
Each feed message is logged when picked up by the SDK from the underlying rabbit mq library. GeneratedAt is the timestamp when the message was created on the server side, ReceivedAt when it was picked up by the SDK (when it entered SDK processing pipeline) and Age the difference in ms. Depends on the message type it may or may not have associated EventId.
Example
2023-05-16 13:08:32,571 INFO [com:5671)] RabbitMqMessageReceiver Message received. Message=[alive ProducerId=5, GeneratedAt=1684235311215, ReceivedAt=1684235312545, Age=1330].
2023-05-16 13:08:32,571 INFO [com:5671)] RabbitMqMessageReceiver Message received. Message=[odds_change ProducerId=3, EventId=sr:match:41286131, GeneratedAt=1684235310565, ReceivedAt=1684235312544, Age=1979].
4. Producer Recovery Logs
Handling recovery process and monitoring producer state is complex mechanism within SDK. It produces log messages for every change between states, with relevant data. Some of the checks are done on every message, and some on timer (in case no message arrive).
On timer (every 10s) it also checks the state of the producer. That is the state as sdk sees it, and does not reflect the state of the server producer.
Example
2023-05-16 13:08:35,108 INFO [com:5671)] ProducerRecoveryManager Recovery with requestId=173202825 for producer=15 completed in 527 ms.
2023-05-16 13:08:35,108 INFO [com:5671)] ProducerRecoveryManager VBI Status changed from Started to Completed.
5. Internal state of producer
When criteria is met which would cause the change of sdk internal state of producer, logs can provide insight what is the reason for change.
Example
2023-05-16 13:09:46,972 WARN [16] ProducerRecoveryManager Producer id=9: no alive messages arrived since 16/05/2023 13:08:23. New recovery will be done.
2023-05-16 13:09:46,972 INFO [16] ProducerRecoveryManager Producer=9: Recovery operation skipped. Last done at 16/05/2023 13:09:26
6. Timer-Based Checks:
On timer the state of each available producer is checked. Tracking is also done for each configured session.
The "age" specifies the time elapsed from message generation (by the feed) and the current time (i.e. current_time - message_generation_time).
The "latency" specifies the time elapsed message generation (by the feed) and when it was received by the SDK(i.e. message_receival_time - message_generation_time).
Log entry explanation: The entry can be break-down into two parts:
Producer info: 1(LO):[IsUp=False,Timestamp=01.01.0001-00:00:00.000(Started)
1(LO) - the id and name of the producer
IsUp=False - whether the producer is marked as "up" or "down" at a moment the entry was written
Timestamp=01.01.0001-00:00:00.000 - The "Timestamp before disconnect" - indicating the time from which the recovery has to be made if the SDK is restarted. Value 01.01.0001-00:00:00.000 is a min date/time that can be represented in .net framework and indicates that a full recovery needs to be done.
(Started) - internal state of the producer. The following values are defined:
NotStarted - the recovery has not been started yet
Started - the recovery has been started and is still in progress
Completed - the recovery has been completed and the status of the producer is up-to-date
Error - the recovery has failed and will be re-started when the next alive is received from the feed
FatalError - the recovery has failed with un-recoverable error and will not be attempted again. This only happens when the recovery timestamp is set to much in the past and therefore cannot be initiated.
Delayed - the recovery has been completed and the status of the producer is up-to-date, but the user is falling behind with message processing (processing is to slow).
timing info: [[Ping(Ok):age=00:00:01,918],[IsBehind(True):Alive(s)[all:age=00:08:17,088],NonAlives[all:latency=00:05:20,859]]].
Ping(Ok) - whether the producer is behaving as expected (based on the age of the last alive message being smaller than maxInactivitySeconds config property
age=00:00:01,918 - the age of the last alive message received on a session which is not affected by other messages
IsBehind(True) - specifies whether the user is falling behind on message processing. The producer is considered as "behind" when either latency or age of any message is larger than maxInactivitySeconds
Alive(s)[all:age=00:08:17,088] - the age of last alive message received on user created sessions. If the user created more than one session, the output will specify multiple ages
NonAlives[all:latency=00:05:20,859] - the latency of last non-alive (bet_stop, odds_change) message received on user created sessions. If the user created more than one session, the output will specify multiple latencies
Example
2023-05-16 13:10:17,277 INFO [11] ProducerRecoveryManager Status check: Producer=5(PremiumCricket):[IsUp=False,Timestamp=16.05.2023-11:28:23.693](Started), Timing Info=[[Ping(Ok):age=00:00:06.453],[IsBehind(True):Alive(s)[prematch:age=00:01:46.062,live:age=00:01:53.498],NonAlives[prematch:latency=00:00:27.918,live:latency=00:00:00.000]]]
7. Recovery Request Logs
Closely related is also RecoveryRequestIssuer. When new API call for recovery request needs to be made, it logs which kind of recovery is done.
Example
2023-05-16 13:08:36,715 INFO [23] RecoveryRequestIssuer Recovery since after timestamp for Producer=8(VBL):[IsUp=False,Timestamp=16.05.2023-11:28:23.693], RequestId=173202830, After=16/05/2023 11:28:23 succeeded.
2023-05-16 13:08:38,653 INFO [15] RecoveryRequestIssuer Full odds recovery for Producer=17(VCI):[IsUp=False,Timestamp=01.01.0001-00:00:00.000], RequestId=173202841 succeeded.
8. API Call Logs (DataRouterManager)
DataRouterManager handles majority of API calls. The log message shows which endpoint was called, parameters and how long it took. Taken time is for the full method execution and not just pure HttpClient request (for that associated log entry can be checked in RestTraffic log). Saving indicates how long the sdk needed to distribute received data between internal caches. This is logged only if it takes longer then 20ms.
Example
2023-05-18 13:08:35,510 INFO [27] DataRouterManager Executing GetSportEventsForDateAsync for date=18/05/2023 and culture=en took 1711 ms.
2023-05-18 13:09:03,438 INFO [23] DataRouterManager Executing GetSportEventSummaryAsync for id=sr:match:39463751 and culture=en took 103 ms.
2023-05-18 13:09:19,873 INFO [23] DataRouterManager Executing GetSportEventSummaryAsync for id=sr:season:95457 and culture=es took 106 ms. Saving took 205 ms.
9. RestTraffic Logs
All the API calls are logged in RestTraffic. Based on the log level set by the user, the logs can be different. On info level just traceId, url and duration is logged. On debug level also the actual xml received from the API is logged. Debug level is recommended during integration period. When exception happens all the data is logged. INFO log example
2025-03-25 15:03:00,789 INFO [17] RestTraffic TraceId: 2a546bb8-b73a-4edc-8861-5a4e0cc811dc GET: https://stgapi.betradar.com/v1/descriptions/en/match_status.xml took 235 ms
2025-03-25 15:03:00,850 INFO [17] RestTraffic TraceId: 98a9d20f-f43e-4b84-8449-ecf3cfbbf187 GET: https://stgapi.betradar.com/v1/descriptions/void_reasons.xml took 40 ms
DEBUG log example
2025-03-25 15:00:00,693 DEBUG [16] RestTraffic TraceId: 26911f24-3db9-4d2a-94c8-5f045e82ab7d GET: https://stgapi.betradar.com/v1/descriptions/void_reasons.xml took 41 ms Response:
<?xml version="1.0" encoding="UTF-8" standalone="yes"?><void_reasons_descriptions response_code="OK"><void_reason id="0" description="OTHER"/><void_reason id="1" description="NO_GOALSCORER"/><void_reason id="2" description="CORRECT_SCORE_MISSING"/><void_reason id="3" description="RESULT_UNVERIFIABLE"/><void_reason id="4" description="FORMAT_CHANGE"/><void_reason id="5" description="CANCELLED_EVENT"/><void_reason id="6" description="MISSING_GOALSCORER"/><void_reason id="7" description="MATCH_ENDED_IN_WALKOVER"/><void_reason id="8" description="DEAD_HEAT"/><void_reason id="9" description="RETIRED_OR_DEFAULTED"/><void_reason id="10" description="EVENT_ABANDONED"/><void_reason id="11" description="EVENT_POSTPONED"/><void_reason id="12" description="INCORRECT_ODDS"/><void_reason id="13" description="INCORRECT_STATISTICS"/><void_reason id="14" description="NO_RESULT_ASSIGNABLE"/><void_reason id="15" description="CLIENT_SIDE_SETTLEMENT_NEEDED"/><void_reason id="16" description="STARTING_PITCHER_CHANGED"/></void_reasons_descriptions>
2025-03-25 15:00:00,738 DEBUG [9] RestTraffic TraceId: eecf0f4d-d0ba-42dd-9f04-68bc968df7b0 GET: https://stgapi.betradar.com/v1/descriptions/betstop_reasons.xml took 44 ms Response:
<?xml version="1.0" encoding="UTF-8" standalone="yes"?><betstop_reasons_descriptions response_code="OK"><betstop_reason id="0" description="UNKNOWN"/><betstop_reason id="1" description="POSSIBLE_GOAL"/><betstop_reason id="2" description="POSSIBLE_RED_CARD"/><betstop_reason id="3" description="SCOUT_LOST"/><betstop_reason id="4" description="POSSIBLE_GOAL_HOME"/><betstop_reason id="5" description="POSSIBLE_GOAL_AWAY"/></betstop_reasons_descriptions
10. SportEventStatus Logs
Receiving SportEventStatus from timeline endpoint can be cached or ignored based on user configuration property IgnoreBetPalTimelineSportEventStatus (default false). As name implies only SportEventStatus received in response from timeline endpoint for events associated with BetPal producer will be ignored.
Example
2025-03-25 13:08:35,510 INFO [27] SportEventStatusCache Received SES for {EventId} from {Source} with EventStatus:{SportEventStatus} (timeline ignored) {StatusOnEvent}
Last updated
Was this helpful?