Hi,
I don't have the previous logs, so I restarted MM2, that produces the same
results. So new logs:
MM2 starts and seems to be ready, but not mirroring message:
[2020-03-20 10:50:11,985] INFO [Producer
clientId=connector-producer-MirrorCheckpointConnector-0] Cluster ID:
700ZEsu0ShuzPZ6lZE54_Q (org.apache.kafka.clients.Metadata)
[2020-03-20 10:50:19,927] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
It takes another 5 minutes of just the usually "committing offsets" kinda
messages (these are all the logs MM2 prints at that time)
[2020-03-20 10:50:19,927] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:19,927] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:19,936] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 9 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,634] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,635] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,639] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,639] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:50:57,650] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 11 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,887] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:11,887] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:19,936] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:19,936] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:19,941] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 5 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,635] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,635] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,651] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,651] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:51:57,658] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 7 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,886] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,933] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Finished commitOffsets
successfully in 47 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,933] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,933] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,965] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Finished commitOffsets
successfully in 32 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,965] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,965] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,997] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Finished commitOffsets
successfully in 32 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,997] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:11,997] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:12,026] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Finished commitOffsets
successfully in 29 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:19,941] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:19,941] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:19,946] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 5 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,635] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,635] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,637] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,637] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,658] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,658] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:52:57,666] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 8 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:11,933] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:11,933] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:11,988] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Finished commitOffsets
successfully in 55 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:11,988] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:11,988] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,027] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Finished commitOffsets
successfully in 39 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,027] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,027] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,067] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Finished commitOffsets
successfully in 40 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,067] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,067] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:12,102] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Finished commitOffsets
successfully in 35 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:19,946] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:19,946] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:19,950] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 4 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,637] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,637] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,667] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,667] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:53:57,682] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 15 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:11,988] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:11,988] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,036] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Finished commitOffsets
successfully in 48 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,036] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,036] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,067] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Finished commitOffsets
successfully in 31 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,067] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,067] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,101] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Finished commitOffsets
successfully in 34 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,102] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,102] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:12,134] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Finished commitOffsets
successfully in 32 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:19,951] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:19,951] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:19,955] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 4 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,636] INFO WorkerSourceTask{id=MirrorSourceConnector-1}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,637] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,637] INFO WorkerSourceTask{id=MirrorSourceConnector-2}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,638] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-0}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,639] INFO WorkerSourceTask{id=MirrorSourceConnector-3}
flushing 0 outstanding messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,682] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,682] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:54:57,690] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 8 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,036] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,036] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,068] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-1} Finished commitOffsets
successfully in 32 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,068] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,068] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,099] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-2} Finished commitOffsets
successfully in 31 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,102] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,102] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,138] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-3} Finished commitOffsets
successfully in 36 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,138] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,138] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:12,169] INFO
WorkerSourceTask{id=MirrorCheckpointConnector-0} Finished commitOffsets
successfully in 31 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:19,955] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Committing offsets
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:19,955] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} flushing 0 outstanding
messages for offset commit
(org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:19,960] INFO
WorkerSourceTask{id=MirrorHeartbeatConnector-0} Finished commitOffsets
successfully in 5 ms (org.apache.kafka.connect.runtime.WorkerSourceTask)
[2020-03-20 10:55:31,729] INFO [Consumer clientId=consumer-14,
groupId=null] Subscribed to partition(s): ...
and then subscribes to the topics and starts to mirror message:
[2020-03-20 10:55:31,729] INFO [Consumer clientId=consumer-14,
groupId=null] Subscribed to partition(s): ...
[2020-03-20 10:55:31,731] INFO Starting with 303 previously uncommitted
partitions. (org.apache.kafka.connect.mirror.MirrorSourceTask)
[2020-03-20 10:55:31,732] INFO [Consumer clientId=consumer-14,
groupId=null] Seeking to offset 180324042 for partition ...
There isn't any logs with "x took too long (y ms)" or "timed out running
task x"?
Only some "x took y ms", but all of them during the startup and it does not
seem to be a reason for the 5 minute delay:
[2020-03-20 10:49:13,980] INFO Reflections took 1443 ms to scan 92 urls,
producing 4486 keys and 18097 values [using 2 cores]
(org.reflections.Reflections)
[2020-03-20 10:49:14,986] INFO Reflections took 653 ms to scan 92 urls,
producing 4486 keys and 18097 values [using 2 cores]
(org.reflections.Reflections)
[2020-03-20 10:49:16,059] INFO Reflections took 618 ms to scan 92 urls,
producing 4486 keys and 18097 values [using 2 cores]
(org.reflections.Reflections)
[2020-03-20 10:49:19,929] INFO creating internal topics took 13 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:20,997] INFO creating internal topics took 10 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,637] INFO creating internal topics took 21 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,658] INFO creating upstream offset-syncs topic took 29
ms (org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,658] INFO creating internal topics took 33 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,680] INFO loading initial consumer groups took 21 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,953] INFO loading initial set of topic-partitions took
295 ms (org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,964] INFO creating downstream topic-partitions took 10
ms (org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,980] INFO refreshing known target topics took 15 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:49:57,981] INFO Starting MirrorSourceConnector took 367 ms.
(org.apache.kafka.connect.mirror.MirrorSourceConnector)
[2020-03-20 10:49:58,442] INFO syncing topic configs took 461 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,316] INFO Stopping MirrorSourceConnector took 6051 ms.
(org.apache.kafka.connect.mirror.MirrorSourceConnector)
[2020-03-20 10:50:07,329] INFO creating upstream offset-syncs topic took 9
ms (org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,395] INFO loading initial set of topic-partitions took
66 ms (org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,397] INFO creating downstream topic-partitions took 2
ms (org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,412] INFO refreshing known target topics took 15 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,412] INFO Starting MirrorSourceConnector took 95 ms.
(org.apache.kafka.connect.mirror.MirrorSourceConnector)
[2020-03-20 10:50:07,430] INFO creating internal topics took 13 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,448] INFO creating internal topics took 13 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,457] INFO loading initial consumer groups took 8 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:07,844] INFO syncing topic configs took 432 ms
(org.apache.kafka.connect.mirror.Scheduler)
[2020-03-20 10:50:09,755] INFO Stopping DistributedHerder-connect-1 took
922 ms. (org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:10,749] INFO Stopping DistributedHerder-connect-1 took
994 ms. (org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:10,755] INFO Stopping DistributedHerder-connect-1 took 6
ms. (org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:11,749] INFO Stopping DistributedHerder-connect-1 took
994 ms. (org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:11,859] INFO Stopping
task-thread-MirrorCheckpointConnector-3 took 3 ms.
(org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:11,861] INFO Stopping
task-thread-MirrorCheckpointConnector-2 took 7 ms.
(org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:11,861] INFO Stopping
task-thread-MirrorCheckpointConnector-0 took 5 ms.
(org.apache.kafka.connect.mirror.MirrorCheckpointTask)
[2020-03-20 10:50:11,862] INFO Stopping
task-thread-MirrorCheckpointConnector-1 took 6 ms.
(org.apache.kafka.connect.mirror.MirrorCheckpointTask)
Peter
On Wed, 18 Mar 2020 at 15:12, Ryanne Dolan <ryannedo...@gmail.com> wrote:
> Peter, can you share any log lines like "x took y ms" or "x took too long
> (y ms)" or "timed out running task x"?
>
> Ryanne
>
> On Tue, Mar 17, 2020 at 10:45 AM Péter Sinóros-Szabó
> <peter.sinoros-sz...@transferwise.com.invalid> wrote:
>
> > Hey,
> >
> > Running a MM2 cluster to mirror from A->B clusters I noticed that when I
> > add a new topic to A cluster, MM2 will notice it:
> > [2020-03-17 13:14:05,477] INFO Found 2719 topic-partitions on main. 1 are
> > new. 0 were removed. Previously had 2718.
> > (org.apache.kafka.connect.mirror.MirrorSourceConnector)
> >
> > That's fine. It seems that MM2 connectors just simply restart to start up
> > with the new configuration.
> > My problem is that it takes about 5 minutes for MM2 to start to mirror
> > messages again.
> >
> > What I see in the logs are:
> > [2020-03-17 13:14:07,107] INFO Kafka startTimeMs: 1584450847106
> > (org.apache.kafka.common.utils.AppInfoParser)
> > [2020-03-17 13:14:07,204] INFO [Producer clientId=producer-11] Cluster
> ID:
> > wif2mnkZTayzAEOb2VyoLA (org.apache.kafka.clients.Metadata)
> >
> > It seems that MM2 restarts the connectors in 2 seconds.
> > But then I see the usual logs, but according to MM2's metrics, it is not
> > mirroring any messages for about 5 minutes.
> >
> > [2020-03-17 13:14:10,485] INFO
> > WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
> > (org.apache.kafka.connect.runtime.WorkerSourceTask)
> > [2020-03-17 13:14:10,485] INFO
> > WorkerSourceTask{id=MirrorCheckpointConnector-3} Committing offsets
> > (org.apache.kafka.connect.runtime.WorkerSourceTask)
> > [2020-03-17 13:14:10,485] INFO
> > WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
> > messages for offset commit
> > (org.apache.kafka.connect.runtime.WorkerSourceTask)
> > [2020-03-17 13:14:10,485] INFO
> > WorkerSourceTask{id=MirrorCheckpointConnector-3} flushing 0 outstanding
> > messages for offset commit
> > (org.apache.kafka.connect.runtime.WorkerSourceTask)
> > [2020-03-17 13:14:10,637] INFO
> > WorkerSourceTask{id=MirrorCheckpointConnector-3} Finished commitOffsets
> > successfully in 152 ms
> (org.apache.kafka.connect.runtime.WorkerSourceTask)
> > [2020-03-17 13:14:10,637] INFO
> > WorkerSourceTask{id=MirrorCheckpointConnector-3} Finished commitOffsets
> > successfully in 152 ms
> (org.apache.kafka.connect.runtime.WorkerSourceTask)
> >
> > So after ~5 minutes, I see that it is subscribing to the topics... and I
> > also see in the metrics that that is the time when it starts to mirror
> > messages.
> >
> > [2020-03-17 13:19:39,850] INFO [Consumer clientId=consumer-39,
> > groupId=null] Subscribed to partition(s): ...
> > [2020-03-17 13:19:39,851] INFO Starting with 308 previously uncommitted
> > partitions. (org.apache.kafka.connect.mirror.MirrorSourceTask)
> > [2020-03-17 13:19:39,851] INFO [Consumer clientId=consumer-39,
> > groupId=null] Seeking to offset 178508243 for partition
> > twTasks.austrac-service.executeTask.default-0 (org.apache.kafka
> >
> >
> > Is there any idea how to speed this up?
> >
> > Thanks,
> > Peter
> >
>
