Hi guys,
Need some help troubleshooting an issue in topology built using trident API.
We have built a topology to do stream data processing and recently we observed
that there will be stalls from time to time. We tried to identify the issue and
narrowed down the scope to a piece of topology that we are doing partition on
stream data before they are sent to a state query function. Our stream data
would be transferred to the query function but the processing didn't continue
even when all the data a transferred.
After enable the debug option for the cluster, we tried to filtered out the
below logs. Bolt b-21 is doing the state query while b-17 are doing aggregation
and also partitioning (a custom partitioner). What we found here is some of the
b-17 tasks failed to send the $coord-bg0 message in batch [52:1] and I think
the b-21 was waiting until the batch times out and causing the batch to be
replayed.
My questions are: are we in the right direction or does the log below looks
normal? How can we look further to see why the bolt b-17 didn't send out
$coord-bg0 message to tell that one batch is over?
Thanks in advance
Yeling
FYI, the log traces.
ubuntu@ipXXX:~/logs$ grep "b-21\].\+received.\+coord-bg0.\+\[51\:0" worker-670*
worker-6701.log.6:12-17 04:32:57.611 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:136,
stream: $coord-bg0, id: {-7136713292474834469=-851420934578354003}, [51:0, 0]
worker-6701.log.6:12-17 04:32:57.775 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:133,
stream: $coord-bg0, id: {-7136713292474834469=2440017194786342385}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.024 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:138,
stream: $coord-bg0, id: {-7136713292474834469=7735035695997037324}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.045 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:127,
stream: $coord-bg0, id: {-7136713292474834469=4040183849563831578}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.075 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:143,
stream: $coord-bg0, id: {-7136713292474834469=8743869519057475603}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.090 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:142,
stream: $coord-bg0, id: {-7136713292474834469=3600421623248941342}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.217 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:130,
stream: $coord-bg0, id: {-7136713292474834469=-3328019112652800752}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.284 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:129,
stream: $coord-bg0, id: {-7136713292474834469=-3738487491821459722}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.335 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:124,
stream: $coord-bg0, id: {-7136713292474834469=6231704250066582606}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.432 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:141,
stream: $coord-bg0, id: {-7136713292474834469=-7477334660878309416}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.469 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:126,
stream: $coord-bg0, id: {-7136713292474834469=168050796225596043}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.511 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:139,
stream: $coord-bg0, id: {-7136713292474834469=6953514965481684202}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.550 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:137,
stream: $coord-bg0, id: {-7136713292474834469=-6398421267889633059}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.595 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:135,
stream: $coord-bg0, id: {-7136713292474834469=-1856394386144516032}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.697 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:125,
stream: $coord-bg0, id: {-7136713292474834469=-1779652479081346578}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.714 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:131,
stream: $coord-bg0, id: {-7136713292474834469=-253596241138150373}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.833 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:128,
stream: $coord-bg0, id: {-7136713292474834469=-2574071615014628831}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.946 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:132,
stream: $coord-bg0, id: {-7136713292474834469=-4302616177471329449}, [51:0, 0]
worker-6701.log.6:12-17 04:32:58.967 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:134,
stream: $coord-bg0, id: {-7136713292474834469=4966768859147190967}, [51:0, 0]
worker-6701.log.6:12-17 04:32:59.391 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:140,
stream: $coord-bg0, id: {-7136713292474834469=7520093913876960459}, [51:0, 0]
ubuntu@ipXXX:~/logs$ grep "b-21\].\+received.\+coord-bg0.\+\[52\:0" worker-670*
worker-6701.log.6:12-17 04:33:04.814 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:132,
stream: $coord-bg0, id: {2591894867587822468=7693090773101058096}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.043 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:125,
stream: $coord-bg0, id: {2591894867587822468=-4763231995168893928}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.072 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:138,
stream: $coord-bg0, id: {2591894867587822468=5012888072654420981}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.207 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:129,
stream: $coord-bg0, id: {2591894867587822468=1531664186653117727}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.223 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:130,
stream: $coord-bg0, id: {2591894867587822468=7385954631194101038}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.253 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:142,
stream: $coord-bg0, id: {2591894867587822468=4496196083010077992}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.257 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:136,
stream: $coord-bg0, id: {2591894867587822468=8523874508220079497}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.322 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:126,
stream: $coord-bg0, id: {2591894867587822468=-6989619861546777699}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.346 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:124,
stream: $coord-bg0, id: {2591894867587822468=2537270258466514056}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.481 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:134,
stream: $coord-bg0, id: {2591894867587822468=3736441829967207066}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.486 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:128,
stream: $coord-bg0, id: {2591894867587822468=4447728067424207151}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.528 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:133,
stream: $coord-bg0, id: {2591894867587822468=-4055845633578069985}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.686 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:140,
stream: $coord-bg0, id: {2591894867587822468=-2971008607810185363}, [52:0, 0]
worker-6701.log.6:12-17 04:33:05.772 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:137,
stream: $coord-bg0, id: {2591894867587822468=-4674113403613652830}, [52:0, 0]
worker-6701.log.6:12-17 04:33:06.377 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:141,
stream: $coord-bg0, id: {2591894867587822468=-9089824651865319735}, [52:0, 0]
worker-6701.log.6:12-17 04:33:06.771 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:135,
stream: $coord-bg0, id: {2591894867587822468=-8367916461523635307}, [52:0, 0]
ubuntu@ipXXX:~/logs$ grep "b-21\].\+received.\+coord-bg0.\+\[52\:1" worker-670*
worker-6701.log.6:12-17 04:33:35.791 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:140,
stream: $coord-bg0, id: {-8661870167326040675=4648554645499723233}, [52:1, 0]
worker-6701.log.6:12-17 04:33:35.948 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:136,
stream: $coord-bg0, id: {-8661870167326040675=348484095349122103}, [52:1, 0]
worker-6701.log.6:12-17 04:33:35.966 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:128,
stream: $coord-bg0, id: {-8661870167326040675=1881696101964944321}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.249 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:138,
stream: $coord-bg0, id: {-8661870167326040675=-5351210827876891431}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.310 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:126,
stream: $coord-bg0, id: {-8661870167326040675=-1551931278924159689}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.345 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:134,
stream: $coord-bg0, id: {-8661870167326040675=2282913014494394740}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.390 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:131,
stream: $coord-bg0, id: {-8661870167326040675=-7702908604766793910}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.420 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:143,
stream: $coord-bg0, id: {-8661870167326040675=-407236442450170255}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.442 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:132,
stream: $coord-bg0, id: {-8661870167326040675=-5675538948909289180}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.443 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:137,
stream: $coord-bg0, id: {-8661870167326040675=-5608534857657388193}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.578 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:127,
stream: $coord-bg0, id: {-8661870167326040675=3036387979937609120}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.654 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:129,
stream: $coord-bg0, id: {-8661870167326040675=-3311581697327530618}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.682 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:141,
stream: $coord-bg0, id: {-8661870167326040675=-3027466019563123695}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.720 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:124,
stream: $coord-bg0, id: {-8661870167326040675=728782990161311378}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.794 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:125,
stream: $coord-bg0, id: {-8661870167326040675=-8054262538408987029}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.822 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:133,
stream: $coord-bg0, id: {-8661870167326040675=7585463731393324258}, [52:1, 0]
worker-6701.log.6:12-17 04:33:36.893 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:135,
stream: $coord-bg0, id: {-8661870167326040675=2104209486014121348}, [52:1, 0]
worker-6701.log.6:12-17 04:33:37.091 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:130,
stream: $coord-bg0, id: {-8661870167326040675=-5607762502001426131}, [52:1, 0]
worker-6701.log.6:12-17 04:33:37.225 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:139,
stream: $coord-bg0, id: {-8661870167326040675=2575498847513810818}, [52:1, 0]
worker-6701.log.6:12-17 04:33:37.293 [Thread-23-b-21] INFO
backtype.storm.daemon.executor - Processing received message source: b-17:142,
stream: $coord-bg0, id: {-8661870167326040675=8175553514248419592}, [52:1, 0]
