{"action":"created","issue":{"url":"https://api.github.com/repos/OpenTSDB/opentsdb/issues/1387","repository_url":"https://api.github.com/repos/OpenTSDB/opentsdb","labels_url":"https://api.github.com/repos/OpenTSDB/opentsdb/issues/1387/labels{/name}","comments_url":"https://api.github.com/repos/OpenTSDB/opentsdb/issues/1387/comments","events_url":"https://api.github.com/repos/OpenTSDB/opentsdb/issues/1387/events","html_url":"https://github.com/OpenTSDB/opentsdb/issues/1387","id":372669910,"node_id":"MDU6SXNzdWUzNzI2Njk5MTA=","number":1387,"title":"Metasync appears to hang","user":{"login":"johnseekins","id":5665929,"node_id":"MDQ6VXNlcjU2NjU5Mjk=","avatar_url":"https://avatars1.githubusercontent.com/u/5665929?v=4","gravatar_id":"","url":"https://api.github.com/users/johnseekins","html_url":"https://github.com/johnseekins","followers_url":"https://api.github.com/users/johnseekins/followers","following_url":"https://api.github.com/users/johnseekins/following{/other_user}","gists_url":"https://api.github.com/users/johnseekins/gists{/gist_id}","starred_url":"https://api.github.com/users/johnseekins/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/johnseekins/subscriptions","organizations_url":"https://api.github.com/users/johnseekins/orgs","repos_url":"https://api.github.com/users/johnseekins/repos","events_url":"https://api.github.com/users/johnseekins/events{/privacy}","received_events_url":"https://api.github.com/users/johnseekins/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":4,"created_at":"2018-10-22T19:46:01Z","updated_at":"2018-10-24T20:51:36Z","closed_at":null,"author_association":"NONE","body":"```\r\nroot@use1-hadoop-4:~# sudo -u opentsdb /usr/share/opentsdb/bin/tsdb version\r\nnet.opentsdb.tools 2.3.1 built at revision 1478380 (MINT)\r\nBuilt on 2018/05/22 00:28:29 +0000 by hobbes@clhbase:/home/hobbes/OFFICIAL/build\r\n```\r\nEvery time I attempt to manually sync metadata, the job will run for a short period, then _appear_ to hang. I say \"appear\" because the log of uidmeta objects being created stops progressing, but stracing the metasync process shows activity (although it doesn't look like _useful_ activity).\r\nThe log will look similar to:\r\n```\r\n19:42:22.492 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D500000100078D00000500002F00000900005600000F00051200001B00092200001C00011000001D000058]\r\n19:42:22.492 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D500000100085900000500002F00000900005600000F00002500001B00055A00001C00005400001D000058]\r\n19:42:22.492 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D50000010007CA00000500002F00000900005600000F0000CA00001B00092200001C00011000001D000058]\r\n19:42:22.492 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D500000100078B00000500002F00000900005600000F00002500001B00055A00001C00005C00001D000058]\r\n19:42:22.493 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D500000100031100000500000600000900005600001B0007B300001C00055D00001D000064]\r\n19:42:22.493 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D500000100086500000500009B00000900005600000F0003FB00001B00055A00001C00005400001D000058]\r\n19:42:22.493 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D50000010009AD00000500002F00000900005600000F00002500001B00092200001C00011000001D000058]\r\n19:42:22.493 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D80000010007C300000500002F00000900005600000F00030800001B00096D00001C00005400001D000064]\r\n19:42:22.494 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D500000100090400000500000600000900005600000F0000CA00001B00092200001C00011000001D000058]\r\n19:42:22.494 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D80000010007CA00000500002F00000900005600000F0000CA00001B00096D00001C00005400001D000064]\r\n19:42:22.494 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D80000010007F800000500002F00000900005600000F0003FB00001B00096D00001C00005400001D000064]\r\n19:42:22.494 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D800000100024E00000500000600000900005600001B00096D00001C00005400001D000064]\r\n19:42:22.495 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D800000100047500000500000600000900005600001B00096D00001C00005400001D000064]\r\n19:42:22.495 WARN  [TSMeta.call] - Found a counter TSMeta column without a meta for TSUID: 0001D4000001000CC800000500002F00000F000CC7\r\n19:42:22.496 INFO  [MetaSync.call] - Counter exists but meta was null, creating meta data for timeseries [0001D4000001000CC800000500002F00000F000CC7]\r\n19:43:01.998 INFO  [UniqueId.allocateUid] - Creating an ID for kind='tagv' name='dattoarray1bfydata9office365sharepoint127.zfssnapshot1540237294887'\r\n19:43:02.000 INFO  [UniqueId.createReverseMapping] - Got ID=8778 for kind='tagv' name='dattoarray1bfydata9office365sharepoint127.zfssnapshot1540237294887'\r\n19:43:02.002 INFO  [UniqueId.done] - Wrote UIDMeta for: dattoarray1bfydata9office365sharepoint127.zfssnapshot1540237294887\r\n19:43:02.003 INFO  [UniqueId.done] - Completed pending assignment for: dattoarray1bfydata9office365sharepoint127.zfssnapshot1540237294887\r\n19:43:02.003 INFO  [UniqueId.allocateUid] - Creating an ID for kind='tagv' name='dattoarraybfydata91271540237294887'\r\n19:43:02.005 INFO  [UniqueId.createReverseMapping] - Got ID=8780 for kind='tagv' name='dattoarraybfydata91271540237294887'\r\n19:43:02.007 INFO  [UniqueId.done] - Wrote UIDMeta for: dattoarraybfydata91271540237294887\r\n19:43:02.008 INFO  [UniqueId.done] - Completed pending assignment for: dattoarraybfydata91271540237294887\r\n```\r\nAll data from then on no longer mentions Meta threads...\r\n\r\nEach subsequent run of metasync seems to at least be \"progressing\" in the sense that the UID that shows up at the end of the list is different every time.\r\n\r\nAlso, each metasync run has at least one appearance of this stacktrace (albeit with a different row mentioned):\r\n```\r\n22:13:45.269 ERROR [MetaSync.call] - Unknown exception processing row: [KeyValue(key=[5, 0, 0, 1, 91, -64, -88, -32, 0, 0, 1, 0, 0, 1, 0, 0, 5, 0, 0, 6], family=\"t\", qualifier=[41, 91, 45, 27, 48, -53, 52, -101, 56, 91, 60, 27, 63, -37, 67, -101, 71, 91, 75, 27, 78, -37, 82, -101, 86\r\n, 75, 90, 27, 93, -53, 97, -101, 101, 75, 105, 27, 108, -37, 112, -101, 116, 91, 120, 27, 123, -37, 127, -117, -125, 91, -121, 27, -118, -37, -114, -101, -110, 75, -106, 11, -103, -37, -99, -101, -95, 91, -91, 27, -88, -37, -84, -101, -80, 91, -76, 27, -73, -53, -69, -117, -65, 91, -\r\n61, 27, -58, -53, -54, -101, -50, 91, -46, 27, -43, -37, -39, -101, -35, 91], value=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0\r\n, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, \r\n0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], timestamp=1539357304788)]\r\njava.lang.IllegalMonitorStateException: null\r\n        at java.util.concurrent.locks.ReentrantLock$Sync.tryRelease(ReentrantLock.java:151) ~[na:1.8.0_181]\r\n        at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1261) ~[na:1.8.0_181]\r\n        at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457) ~[na:1.8.0_181]\r\n        at net.opentsdb.tree.TreeBuilder$1ErrorCB.call(TreeBuilder.java:528) ~[tsdb-2.3.1.jar:1478380]\r\n        at net.opentsdb.tree.TreeBuilder$1ErrorCB.call(TreeBuilder.java:524) ~[tsdb-2.3.1.jar:1478380]\r\n        at com.stumbleupon.async.Deferred.doCall(Deferred.java:1278) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1257) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.callback(Deferred.java:1005) [async-1.4.0.jar:na]\r\n        at net.opentsdb.tree.Tree$1AllTreeScanner.call(Tree.java:566) [tsdb-2.3.1.jar:1478380]\r\n        at net.opentsdb.tree.Tree$1AllTreeScanner.call(Tree.java:543) [tsdb-2.3.1.jar:1478380]\r\n        at com.stumbleupon.async.Deferred.doCall(Deferred.java:1278) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1257) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.access$300(Deferred.java:430) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred$Continue.call(Deferred.java:1366) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.doCall(Deferred.java:1278) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1257) [async-1.4.0.jar:na]\r\n        at com.stumbleupon.async.Deferred.callback(Deferred.java:1005) [async-1.4.0.jar:na]\r\n        at org.hbase.async.HBaseRpc.callback(HBaseRpc.java:720) [asynchbase-1.8.2.jar:na]\r\n        at org.hbase.async.RegionClient.decode(RegionClient.java:1575) [asynchbase-1.8.2.jar:na]\r\n        at org.hbase.async.RegionClient.decode(RegionClient.java:88) [asynchbase-1.8.2.jar:na]\r\n        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:500) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.10.6.Final.jar:na]\r\n        at org.hbase.async.RegionClient.handleUpstream(RegionClient.java:1230) [asynchbase-1.8.2.jar:na]\r\n        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.SimpleChannelHandler.messageReceived(SimpleChannelHandler.java:142) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.handler.timeout.IdleStateAwareChannelHandler.handleUpstream(IdleStateAwareChannelHandler.java:36) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.handler.timeout.IdleStateHandler.messageReceived(IdleStateHandler.java:294) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.10.6.Final.jar:na]\r\n        at org.hbase.async.HBaseClient$RegionClientPipeline.sendUpstream(HBaseClient.java:3857) [asynchbase-1.8.2.jar:na]\r\n        at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.10.6.Final.jar:na]\r\n        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.10.6.Final.jar:na]\r\n        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_181]\r\n        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_181]\r\n        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]\r\n```\r\nI did collect a stack trace (`jstack -l <pid>`) if that's helpful..."},"comment":{"url":"https://api.github.com/repos/OpenTSDB/opentsdb/issues/comments/432823500","html_url":"https://github.com/OpenTSDB/opentsdb/issues/1387#issuecomment-432823500","issue_url":"https://api.github.com/repos/OpenTSDB/opentsdb/issues/1387","id":432823500,"node_id":"MDEyOklzc3VlQ29tbWVudDQzMjgyMzUwMA==","user":{"login":"johnseekins","id":5665929,"node_id":"MDQ6VXNlcjU2NjU5Mjk=","avatar_url":"https://avatars1.githubusercontent.com/u/5665929?v=4","gravatar_id":"","url":"https://api.github.com/users/johnseekins","html_url":"https://github.com/johnseekins","followers_url":"https://api.github.com/users/johnseekins/followers","following_url":"https://api.github.com/users/johnseekins/following{/other_user}","gists_url":"https://api.github.com/users/johnseekins/gists{/gist_id}","starred_url":"https://api.github.com/users/johnseekins/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/johnseekins/subscriptions","organizations_url":"https://api.github.com/users/johnseekins/orgs","repos_url":"https://api.github.com/users/johnseekins/repos","events_url":"https://api.github.com/users/johnseekins/events{/privacy}","received_events_url":"https://api.github.com/users/johnseekins/received_events","type":"User","site_admin":false},"created_at":"2018-10-24T20:51:36Z","updated_at":"2018-10-24T20:51:36Z","author_association":"NONE","body":"The result of metasync not working is we can't use template variables in Grafana with OpenTSDB. Which is rather frustrating."}}
{"actor":{"display_login":"johnseekins"}}