Page MenuHomeSoftware Heritage
Paste P525

Kafka consumer crash
ActivePublic

Authored by vlorentz on Sep 10 2019, 12:00 PM.
Sep 10 11:59:01 desktop5 replayer-12301[2746]: INFO:kafka.conn:<BrokerConnection node_id=11 host=esnode1.internal.softwareheritage.org:9092 <connecting> [IPv4 ('192.168.100.61', 9092)]>: connecting to esnode1.internal.softwareheritage.org:9092 [('192.168.100.61', 9092) IPv4]
Sep 10 11:59:06 desktop5 replayer-12301[2746]: INFO:kafka.conn:<BrokerConnection node_id=12 host=esnode2.internal.softwareheritage.org:9092 <connecting> [IPv4 ('192.168.100.62', 9092)]>: connecting to esnode2.internal.softwareheritage.org:9092 [('192.168.100.62', 9092) IPv4]
Sep 10 11:59:06 desktop5 replayer-12301[2746]: INFO:kafka.conn:<BrokerConnection node_id=11 host=esnode1.internal.softwareheritage.org:9092 <connecting> [IPv4 ('192.168.100.61', 9092)]>: Connection complete.
Sep 10 11:59:06 desktop5 replayer-12301[2746]: INFO:kafka.conn:<BrokerConnection node_id=12 host=esnode2.internal.softwareheritage.org:9092 <connecting> [IPv4 ('192.168.100.62', 9092)]>: Connection complete.
Sep 10 11:59:19 desktop5 replayer-12301[2746]: WARNING:kafka.coordinator:Heartbeat session expired, marking coordinator dead
Sep 10 11:59:19 desktop5 replayer-12301[2746]: WARNING:kafka.coordinator:Marking the coordinator dead (node 13) for group vlorentz-cassandra-test-0: Heartbeat session expired.
Sep 10 11:59:40 desktop5 replayer-12301[2746]: WARNING:kafka.coordinator:Heartbeat: local member_id was not recognized; this consumer needs to re-join
Sep 10 11:59:40 desktop5 replayer-12301[2746]: Traceback (most recent call last):
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/home/vlorentz-cassandra/.local/bin/swh", line 11, in <module>
Sep 10 11:59:40 desktop5 replayer-12301[2746]: load_entry_point('swh.core', 'console_scripts', 'swh')()
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/home/vlorentz-cassandra/.local/lib/python3.5/site-packages/swh/core/cli/__init__.py", line 56, in main
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return swh(auto_envvar_prefix='SWH')
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/core.py", line 716, in __call__
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return self.main(*args, **kwargs)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/core.py", line 696, in main
Sep 10 11:59:40 desktop5 replayer-12301[2746]: rv = self.invoke(ctx)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/core.py", line 1060, in invoke
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return _process_result(sub_ctx.command.invoke(sub_ctx))
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/core.py", line 1060, in invoke
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return _process_result(sub_ctx.command.invoke(sub_ctx))
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/core.py", line 889, in invoke
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return ctx.invoke(self.callback, **ctx.params)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/core.py", line 534, in invoke
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return callback(*args, **kwargs)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/usr/lib/python3/dist-packages/click/decorators.py", line 17, in new_func
Sep 10 11:59:40 desktop5 replayer-12301[2746]: return f(get_current_context(), *args, **kwargs)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/home/vlorentz-cassandra/swh-journal/swh/journal/cli.py", line 99, in replay
Sep 10 11:59:40 desktop5 replayer-12301[2746]: nb_messages += client.process(worker_fn)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/home/vlorentz-cassandra/swh-journal/swh/journal/client.py", line 108, in process
Sep 10 11:59:40 desktop5 replayer-12301[2746]: self.consumer.commit()
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/home/vlorentz-cassandra/.local/lib/python3.5/site-packages/kafka_python-1.4.6-py3.5.egg/kafka/consumer/group.py", line 520, in commit
Sep 10 11:59:40 desktop5 replayer-12301[2746]: self._coordinator.commit_offsets_sync(offsets)
Sep 10 11:59:40 desktop5 replayer-12301[2746]: File "/home/vlorentz-cassandra/.local/lib/python3.5/site-packages/kafka_python-1.4.6-py3.5.egg/kafka/coordinator/consumer.py", line 514, in commit_offsets_sync
Sep 10 11:59:40 desktop5 replayer-12301[2746]: raise future.exception # pylint: disable-msg=raising-bad-type
Sep 10 11:59:40 desktop5 replayer-12301[2746]: kafka.errors.CommitFailedError: CommitFailedError: Commit cannot be completed since the group has already
Sep 10 11:59:40 desktop5 replayer-12301[2746]: rebalanced and assigned the partitions to another member.
Sep 10 11:59:40 desktop5 replayer-12301[2746]: This means that the time between subsequent calls to poll()
Sep 10 11:59:40 desktop5 replayer-12301[2746]: was longer than the configured max_poll_interval_ms, which
Sep 10 11:59:40 desktop5 replayer-12301[2746]: typically implies that the poll loop is spending too much
Sep 10 11:59:40 desktop5 replayer-12301[2746]: time message processing. You can address this either by
Sep 10 11:59:40 desktop5 replayer-12301[2746]: increasing the rebalance timeout with max_poll_interval_ms,
Sep 10 11:59:40 desktop5 replayer-12301[2746]: or by reducing the maximum size of batches returned in poll()
Sep 10 11:59:40 desktop5 replayer-12301[2746]: with max_poll_records.