{"action":"created","issue":{"url":"https://api.github.com/repos/ganglia/monitor-core/issues/223","labels_url":"https://api.github.com/repos/ganglia/monitor-core/issues/223/labels{/name}","comments_url":"https://api.github.com/repos/ganglia/monitor-core/issues/223/comments","events_url":"https://api.github.com/repos/ganglia/monitor-core/issues/223/events","html_url":"https://github.com/ganglia/monitor-core/issues/223","id":70806471,"number":223,"title":"slow queries to gmetad xml port can block data_threads can cause large gaps in graphs","user":{"login":"cburroughs","id":24433,"avatar_url":"https://avatars.githubusercontent.com/u/24433?v=3","gravatar_id":"","url":"https://api.github.com/users/cburroughs","html_url":"https://github.com/cburroughs","followers_url":"https://api.github.com/users/cburroughs/followers","following_url":"https://api.github.com/users/cburroughs/following{/other_user}","gists_url":"https://api.github.com/users/cburroughs/gists{/gist_id}","starred_url":"https://api.github.com/users/cburroughs/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/cburroughs/subscriptions","organizations_url":"https://api.github.com/users/cburroughs/orgs","repos_url":"https://api.github.com/users/cburroughs/repos","events_url":"https://api.github.com/users/cburroughs/events{/privacy}","received_events_url":"https://api.github.com/users/cburroughs/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":2,"created_at":"2015-04-24T22:08:06Z","updated_at":"2015-04-26T20:58:07Z","closed_at":null,"body":"Background: I have two DCs (I'll call them A & B).  Each DC has a gmetad instance that does the normal gemtad polling (\"normal\" gmetad) and graphing of our clusters.  Each DC also has a 2nd gmetad instance (the \"grid\" instnace) that polls the norml gmetad in A & the normal gmetad in B, but no others.  The intent is that each DC has a full copy of all metrics, but does not need to know the details of the 'other' DC (such as all of the clusters in it).  (RRD retention settings and a few other irrelevant details also differ.)\r\n\r\nWe are seeing cases where external network problems (inter-DC VPN is saturated, our ISP is dropping a lot of packets) where the 'grid' instances have some gaps (expected) *and* the 'normal' instances also have graphs (very bad and unexpected).  This relashionship has been observed serveral times.  My theory is that slow requests to a `server_thread` (because the inter-DC gmetad poll is slowed by the network problems) is causing a `data_thread` to block.\r\n\r\nSynthetic Test:  Using a  script [1] to simulate slow connections I was able to reprodue the condition.\r\n * Run n instnaces of the script against a 'normal' production gmetad, where n > server_threads.  I do not believe this is needed and one is sufficient, but I had done enough damage to our production graphs.\r\n * Wait a few minutes, observe that gaps appear on some clusters.\r\n * Wait  ~10 minutes to confirm the gaps are not a fluke.\r\n * During the above take period stack staces.\r\n * Stop all script instances, gaps go away.\r\n\r\nI repeated the test 3 times over the course of an hour to make sure it was not a fluke.  Extra spooky part: It was the same two clusters affected on each of my tests.  One cluster is among the samllest, the other is among the largest so I dont see a corelation with how many metrics.\r\n\r\nThe stack traces show 2 data_threads allways stuck in `pthread_rwlock_wrlock`:\r\n\r\n```\r\n# grep -A 7  'Thread 17 ' /tmp/stack.t2.*\r\n/tmp/stack.t2.0:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.0-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.0-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.0-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.0-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.0-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.0-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.0-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.1:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.1-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.1-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.1-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.1-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.1-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.1-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.1-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.2:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.2-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.2-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.2-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.2-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.2-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.2-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.2-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.3:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.3-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.3-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.3-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.3-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.3-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.3-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.3-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.4:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.4-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.4-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.4-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.4-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.4-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.4-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.4-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.5:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.5-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.5-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.5-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.5-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.5-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.5-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.5-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.6:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.6-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.6-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.6-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.6-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.6-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.6-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.6-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n--\r\n/tmp/stack.t2.7:Thread 17 (Thread 0x7f27286f8700 (LWP 46994)):\r\n/tmp/stack.t2.7-#0  0x000000365da0ac50 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0\r\n/tmp/stack.t2.7-#1  0x000000359b00bb0a in hash_insert () from /usr/lib64/libganglia.so.0\r\n/tmp/stack.t2.7-#2  0x0000000000408a28 in end ()\r\n/tmp/stack.t2.7-#3  0x0000003661e0a836 in doContent () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.7-#4  0x0000003661e0bbce in contentProcessor () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.7-#5  0x0000003661e0d4fa in doProlog () from /lib64/libexpat.so.1\r\n/tmp/stack.t2.7-#6  0x0000003661e0de3b in prologProcessor () from /lib64/libexpat.so.1\r\n```\r\n\r\nOther threads have stacks that varry (selecting, locking, writing out files, etc).  The stack traces for an entire run are available at : https://gist.github.com/cburroughs/ca5f5fc18765dbd215b0\r\n\r\n[1] \r\n\r\n```python\r\n#!/usr/bin/env python\r\n\r\nimport socket\r\nimport time\r\n\r\nTCP_IP = '10.15.5.73'\r\nTCP_PORT = 8651\r\nBUFFER_SIZE = 1\r\n\r\ndata = ''\r\ns = socket.socket(socket.AF_INET, socket.SOCK_STREAM)\r\ns.connect((TCP_IP, TCP_PORT))\r\nbuf = None\r\ni = 0\r\nwhile True:\r\n    buf = s.recv(BUFFER_SIZE)\r\n    i += 1\r\n    if buf:\r\n        data += buf\r\n        time.sleep(1)\r\n        if i % 25 == 0:\r\n            print 'len: ', len(data)\r\n    else:\r\n        break\r\ns.close()\r\n\r\nprint '-----------------'\r\nprint 'len: ', len(data)\r\nprint 'head: ', data[0:1024]\r\n```\r\n\r\nMy build is `e67ab835c121915794405bf5f8663123d7ff8d21` + #190.  I believe this is substantialy similar to the latest tagged release.\r\n"},"comment":{"url":"https://api.github.com/repos/ganglia/monitor-core/issues/comments/96434342","html_url":"https://github.com/ganglia/monitor-core/issues/223#issuecomment-96434342","issue_url":"https://api.github.com/repos/ganglia/monitor-core/issues/223","id":96434342,"user":{"login":"dhobsd","id":168647,"avatar_url":"https://avatars.githubusercontent.com/u/168647?v=3","gravatar_id":"","url":"https://api.github.com/users/dhobsd","html_url":"https://github.com/dhobsd","followers_url":"https://api.github.com/users/dhobsd/followers","following_url":"https://api.github.com/users/dhobsd/following{/other_user}","gists_url":"https://api.github.com/users/dhobsd/gists{/gist_id}","starred_url":"https://api.github.com/users/dhobsd/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/dhobsd/subscriptions","organizations_url":"https://api.github.com/users/dhobsd/orgs","repos_url":"https://api.github.com/users/dhobsd/repos","events_url":"https://api.github.com/users/dhobsd/events{/privacy}","received_events_url":"https://api.github.com/users/dhobsd/received_events","type":"User","site_admin":false},"created_at":"2015-04-26T20:58:07Z","updated_at":"2015-04-26T20:58:07Z","body":"I wouldn't be surprised. I've really wanted to spend some time reworking the hash table usage in gmetad, but just haven't gotten around to it yet. That said, the time spent in the critical sections hasn't changed IIRC. So if this is happening now, I'm pretty sure it was happening before my changes.\r\n\r\nThe critical sections are unnecessarily heavy and all hash operations end up doing allocations (even if they aren't mutating the hash). Maybe I can set aside a weekend soon to fix this behavior. Is this a pressing issue for you?"}}