Common Logs Explained

The following are the examples of logs you'll find for some common scenarios

  1. 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 and the message is processed and dispatched to the user code normally.

15:04:55,184 [WARN ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-2] [c.s.u.s.i.r.OddsFeedSessionImpl] - Problems were detected while validating message odds_change, but the message is still eligible for further processing. ProducerId:5, EventId:'sr:match:40932447'
  1. Indicates a timeframe the client system took to process a message. Feed messages are time-sensitive and slow processing delays the delivery of the subsequent odds feed messages. If the accumulative delay is higher than a configured threshold - the producer will be marked down to protect the bookmaker from operating stale data and therefore - the punter getting an edge against him.

2023-05-30 15:01:19,790 [WARN ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-2] [c.s.u.s.i.r.RecoveryManagerImpl] - The client took more than 1 second to process a message for producer 3 and event sr:season:105945 (4.018 seconds)
  1. Indicates that producer will not be producing messages. This might be happening due to multiple reasons like producer maintenance windows.

2023-05-30 15:01:36,748 [WARN ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-4] [c.s.u.s.i.r.RecoveryManagerImpl] - Received alive with subscribed=0 from [Producer[14 C-Odds]], initiating recovery
  1. The accumulative delay of processing messages on the customer end is higher than a configured threshold - producer is marked down to protect the bookmaker from operating stale data and therefore - punter getting an edge against him.

2023-05-30 15:04:29,487 [WARN ] [uf-sdk-22020-22] [uf-sdk-22020-22-rm-t-0] [c.s.u.s.i.r.RecoveryManagerImpl] - ProducerDown:ProcessingQueueDelayViolation -> The max processing queue delay(20s) was exceeded, flagging producer as DOWN [Producer[3 Ctrl]]
  1. Indicates producer going down and an associated reason which in this case is too slow processing of messages on the customer end causing the bookmaker to operate with relatively out-dated (delayed) data.

2023-05-30 15:04:29,489 [WARN ] [uf-sdk-22020-22] [uf-sdk-22020-22-rm-t-0] [c.s.u.s.i.r.RecoveryManagerImpl] - ProducerStatusChange[Producer[3 Ctrl]], reason: ProcessingQueueDelayViolation, isFlaggedDown: true, isDelayed: true
  1. Indicates producer is coming back up again and an associated reason for that, which in this case is due to finishing the initial recovery after SDK start up.

2023-05-30 15:04:28,779 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-2] [c.s.u.s.i.r.RecoveryManagerImpl] - ProducerStatusChange[Producer[3 Ctrl]], reason: FirstRecoveryCompleted, isFlaggedDown: false, isDelayed: true
  1. Indicates that certain endpoint is about to be invoked.

2023-05-30 15:01:28,232 [INFO ] [] [pool-12-thread-1] [c.s.u.s.i.LogFastHttpDataFetcher] - Fetching data from: 
https://global.stgapi.betradar.com/v1/descriptions/en/markets/534/variants/pre:markettext:192371?include_mappings=true
  1. A periodic check scheduled to run several times a minute which provides the status of the producers. String Literal "Producer" is followed by:

  • Producer id (which is 1, 3 and 14 in this case)

  • Producer abbreviation (LO for live odds, Ctrl for pre-match and C-Odds in this case)

  • number of seconds lapsed since last receival of feed message by the SDK (excluding processing impact on the customer end completely) 8, 5 and 2 in this case

  • number of seconds lapsed since last processing of feed message by the SKD (including processing impact on the customer end) 9, 5, and 2 in this case

  • producer state (whether it is up or down) - all 3 UP in this case.

2023-05-30 15:05:29,556 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-rm-t-0] [c.s.u.s.i.r.RecoveryManagerImpl] - Producers StatusCheck: (Producer[1 LO]:8:9:UP)(Producer[3 Ctrl]:5:5:UP)(Producer[14 C-Odds]:2:2:UP)
  1. Similar to the previous one, just with additional information provided during the recovery. The producer 3 additionally is indicated to be in the process of performing its recovery.

2023-05-30 15:34:06,153 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-rm-t-0] [c.s.u.s.i.r.RecoveryManagerImpl] - Producers StatusCheck: (Producer[1 LO]:1:5:UP)(Producer[3 Ctrl]:2:2:DOWN - doing recovery, RecoveryState=Started)(Producer[14 C-Odds]:7:6:UP)
  1. Provides information about the message received from the SDK right after it arrives from the server to the SDK. In this case it was received on a user session configured to receive only Prematch messages only, it contains a rabbitMQ routing key, and an xml message content.

2023-05-30 15:07:13,221 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-1] UFSession-PrematchMessagesOnly <~> hi.pre.live.fixture_change.5.sr:match.41491699.- <~> <?xml version="1.0" encoding="UTF-8" standalone="yes"?><fixture_change start_time="1685462700000" product="1" event_id="sr:match:41491699" timestamp="1685452033338"/>
  1. Indicates amount of time it took for the SDK (including customer processing impact) to process the feed message.

2023-05-30 15:07:16,967 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-2] Message -> (1|sr:match:41493435|UFFixtureChange|1685452037084) processing finished on UFSession-LiveMessagesOnly, duration: 0 ms
  1. Indicates the information about failed request providing status code.

2023-05-30 15:34:28,674 [WARN ] [] [pool-12-thread-88] [c.s.u.sdk.impl.HttpDataFetcher] - Bad API response: HTTP/1.1 504 Gateway Time-out 504, message: 'No specific message' 
https://global.stgapi.betradar.com/v1/descriptions/cs/markets/534/variants/pre:markettext:157605?include_mappings=true
2023-05-30 15:34:28,676 [WARN ] [] [pool-12-thread-88] [c.s.u.s.c.m.MarketDescriptionProviderImpl] - There was an error providing the explicit variant market descriptor -> marketId:534, variantValue: pre:markettext:157605, locales: [cs]com.sportradar.unifiedodds.sdk.exceptions.internal.IllegalCacheStateException: An error occurred while fetching variant market[534 pre:markettext:157605] data
  1. Sessions tracks the time frame they do not receive Odds Feed message from the server and after 3 minutes of inactivity close the rabbit connection which is usually represented by the following pattern in the log file, namely channels and connection getting disconnected as well and recoveries being issued.

2023-05-30 15:35:14,975 [WARN ] [] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.RabbitMqChannelImpl] - There were no messages in more then 180s for the channel with channelNumber: 2 (prematch). Last message arrived: 2023-05-30T15:32:11.595
2023-05-30 15:35:15,032 [INFO ] [uf-sdk-22020-22] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.RecoveryManagerImpl] - Channel disconnect detected [initiated by application]
2023-05-30 15:35:15,032 [WARN ] [uf-sdk-22020-22] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.RecoveryManagerImpl] - ProducerDown:ConnectionDown -> Connection to the server was lost, flagging producer as DOWN [Producer[1 LO]]
2023-05-30 15:35:15,034 [WARN ] [uf-sdk-22020-22] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.RecoveryManagerImpl] - ProducerStatusChange[Producer[1 LO]], reason: ConnectionDown, isFlaggedDown: true, isDelayed: false
2023-05-30 15:35:15,034 [INFO ] [uf-sdk-22020-22] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.recovery.ProducerInfo] - Producer[1 LO] recovery state set to: recoveryId[0], recoveryStartedAt[0], recoveryState[Error]
2023-05-30 15:35:15,034 [WARN ] [uf-sdk-22020-22] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.RecoveryManagerImpl] - ProducerDown:ConnectionDown -> Connection to the server was lost, flagging producer as DOWN [Producer[14 C-Odds]]
2023-05-30 15:35:15,035 [INFO ] [] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.RabbitMqChannelImpl] - Resetting connection for the channel with channelNumber: 2
2023-05-30 15:35:16,226 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-rm-t-0] [c.s.u.s.i.r.RecoveryManagerImpl] - Producers StatusCheck: (Producer[1 LO]:5:5:DOWN - ConnectionDown, RecoveryState=Error)(Producer[3 Ctrl]:2:2:DOWN, RecoveryState=Error)(Producer[14 C-Odds]:7:6:DOWN - ConnectionDown, RecoveryState=Error)
  1. In 5 seconds after closing the connection, it is attempted to be recreated which usually is represented with the following pattern in the log file, namely creating the connection, stargin channels and continuing issueing recoveries.

2023-05-30 15:35:22,256 [INFO ] [] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.SingleInstanceAMQPConnectionFactory] - Creating new SDKConnection for global.stgmq.betradar.com
2023-05-30 15:35:22,256 [INFO ] [] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.SingleInstanceAMQPConnectionFactory] - Creating new connection (Sportradar Unified Odds SDK 2.0.60)
2023-05-30 15:35:22,564 [INFO ] [] [MqChannelMonitor-prematch-959055079] [c.s.u.s.i.r.SingleInstanceAMQPConnectionFactory] - Connection created successfully
2023-05-30 15:35:32,334 [WARN ] [] [MqChannelMonitor--312565954] [c.s.u.s.i.r.RabbitMqChannelImpl] - Channel to old. Recreating connection channel ...
2023-05-30 15:35:33,697 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-3] [c.s.u.s.i.r.RecoveryManagerImpl] - Recovery needed for Producer[3 Ctrl] because of state[Error] == NotStarted || Error || Interrupted
2023-05-30 15:35:33,697 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-3] [c.s.u.s.i.recovery.ProducerInfo] - Producer[3 Ctrl] recovery state set to: recoveryId[3785], recoveryStartedAt[1685453733697], recoveryState[Started]
2023-05-30 15:35:33,697 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-amqp-t-3] [c.s.u.s.i.r.RecoveryManagerImpl] - Scheduling recovery request for Producer[3 Ctrl], recoveryId: 3785, recoveryFrom: 1685452788676
2023-05-30 15:35:33,698 [INFO ] [uf-sdk-22020-22] [uf-sdk-22020-22-t-0] [c.s.u.s.i.r.RecoveryManagerImpl] - Initiating recovery on Producer[3 Ctrl], for PT-15M-45.022S back [request_id:3785]

Last updated

Was this helpful?