{"action":"created","issue":{"url":"https://api.github.com/repos/python-diamond/Diamond/issues/595","repository_url":"https://api.github.com/repos/python-diamond/Diamond","labels_url":"https://api.github.com/repos/python-diamond/Diamond/issues/595/labels{/name}","comments_url":"https://api.github.com/repos/python-diamond/Diamond/issues/595/comments","events_url":"https://api.github.com/repos/python-diamond/Diamond/issues/595/events","html_url":"https://github.com/python-diamond/Diamond/issues/595","id":206989419,"number":595,"title":"diamond takes a while to stop, errors out, slows down shutdown","user":{"login":"sandrotosi","id":346648,"avatar_url":"https://avatars1.githubusercontent.com/u/346648?v=3","gravatar_id":"","url":"https://api.github.com/users/sandrotosi","html_url":"https://github.com/sandrotosi","followers_url":"https://api.github.com/users/sandrotosi/followers","following_url":"https://api.github.com/users/sandrotosi/following{/other_user}","gists_url":"https://api.github.com/users/sandrotosi/gists{/gist_id}","starred_url":"https://api.github.com/users/sandrotosi/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sandrotosi/subscriptions","organizations_url":"https://api.github.com/users/sandrotosi/orgs","repos_url":"https://api.github.com/users/sandrotosi/repos","events_url":"https://api.github.com/users/sandrotosi/events{/privacy}","received_events_url":"https://api.github.com/users/sandrotosi/received_events","type":"User","site_admin":false},"labels":[{"id":488425556,"url":"https://api.github.com/repos/python-diamond/Diamond/labels/status:%20fix-provided","name":"status: fix-provided","color":"009800","default":false},{"id":60521885,"url":"https://api.github.com/repos/python-diamond/Diamond/labels/type:%20bug","name":"type: bug","color":"fc2929","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":16,"created_at":"2017-02-11T16:07:01Z","updated_at":"2017-04-05T02:43:44Z","closed_at":null,"body":"Hello,\r\nas reported in Debian at http://bugs.debian.org/854842\r\n\r\n```\r\nIn my setup, diamond takes a long time to stop after getting a SIGTERM\r\nfrom systemd, thus slowing down the overall shutdown of the system by\r\nabout a minute (and also making it slow to perform restarts). When it\r\nfinally does stop, an error message about QueueHandler is emitted. The\r\nissue is reproducible without systemd too -- run diamond in one terminal\r\nwith --log-stdout --foreground and then run kill from another terminal\r\n(Ctrl+C i.e. SIGINT won't reproduce it). This happens even with a\r\nrelatively minimal config, e.g. without any Collectors defined and only\r\nwith a single GraphiteHandler.\r\n\r\nWhat I see here is:\r\nroot@d-i-test:/etc/diamond# diamond --log-stdout --foreground\r\n1486775151.66   [MainProcess:9336:INFO] Changed UID: 0 () GID: 0 ().\r\n1486775152.06   [MainProcess:9336:DEBUG]        metric_queue_size: 16384\r\n1486775152.06   [MainProcess:9336:DEBUG]        Loading Handler diamond.handler.graphite.GraphiteHandler\r\n1486775152.1    [MainProcess:9336:DEBUG]        GraphiteHandler: Established connection to graphite server 10.192.16.33:2003.\r\n1486775152.11   [Handlers:9347:DEBUG]   Starting process Handlers\r\n1486775153.12   [TCPCollector:9350:DEBUG]       Starting\r\n1486775153.12   [TCPCollector:9350:DEBUG]       Interval: 60.0 seconds\r\n1486775153.13   [TCPCollector:9350:DEBUG]       Max collection time: 28 seconds\r\n1486775153.16   [TCPCollector:9350:DEBUG]       Collection took 32 ms\r\n1486775154.14   [NetworkCollector:9353:DEBUG]   Starting\r\n1486775154.14   [NetworkCollector:9353:DEBUG]   Interval: 60.0 seconds\r\n1486775154.14   [NetworkCollector:9353:DEBUG]   Max collection time: 19 seconds\r\n1486775154.16   [NetworkCollector:9353:DEBUG]   Collection took 16 ms\r\n1486775155.15   [DiskUsageCollector:9356:DEBUG] Starting\r\n1486775155.15   [DiskUsageCollector:9356:DEBUG] Interval: 60.0 seconds\r\n1486775155.15   [DiskUsageCollector:9356:DEBUG] Max collection time: 48 seconds\r\n1486775155.15   [DiskUsageCollector:9356:DEBUG] Collection took 1 ms\r\n1486775156.16   [CPUCollector:9359:DEBUG]       Starting\r\n1486775156.16   [CPUCollector:9359:DEBUG]       Interval: 60.0 seconds\r\n1486775156.16   [CPUCollector:9359:DEBUG]       Max collection time: 43 seconds\r\n1486775156.17   [CPUCollector:9359:DEBUG]       Collection took 7 ms\r\n<send kill from another terminal>\r\n1486775186.96   [MainProcess:9336:INFO] Signal Received: 15\r\n1486775186.96   [NetworkCollector:9353:INFO]    Signal Received: 15\r\n1486775186.96   [Handlers:9347:INFO]    Signal Received: 15\r\n1486775186.96   [DiskUsageCollector:9356:INFO]  Signal Received: 15\r\n1486775186.96   [TCPCollector:9350:INFO]        Signal Received: 15\r\n1486775186.96   [CPUCollector:9359:INFO]        Signal Received: 15\r\n1486775186.97   [NetworkCollector:9353:INFO]    Signal Received: 15\r\n1486775186.97   [CPUCollector:9359:INFO]        Signal Received: 15\r\n<long wait>\r\nException socket.error: error(111, 'Connection refused') in <bound method QueueHandler.__del__ of <diamond.handler.queue.QueueHandler object at 0x7f8fa53bff10>> ignored\r\n\r\nWhile this long wait is happening, strace shows diamond is busylooping\r\nrunning this over and over (apparently python multiprocessing related):\r\nconnect(4, {sa_family=AF_UNIX, sun_path=\"/tmp/pymp-xq1DKs/listener-8_h02F\"}, 34) = -1 ECONNREFUSED (Connection refused)\r\nclose(4)                                = 0\r\nselect(0, NULL, NULL, NULL, {tv_sec=0, tv_usec=10000}) = 0 (Timeout)\r\nsocket(AF_UNIX, SOCK_STREAM, 0)         = 4\r\nfcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)\r\nfcntl(4, F_SETFL, O_RDWR)               = 0\r\n```\r\n\r\ncould you have a look at this? thanks!"},"comment":{"url":"https://api.github.com/repos/python-diamond/Diamond/issues/comments/291726838","html_url":"https://github.com/python-diamond/Diamond/issues/595#issuecomment-291726838","issue_url":"https://api.github.com/repos/python-diamond/Diamond/issues/595","id":291726838,"user":{"login":"paravoid","id":1330796,"avatar_url":"https://avatars0.githubusercontent.com/u/1330796?v=3","gravatar_id":"","url":"https://api.github.com/users/paravoid","html_url":"https://github.com/paravoid","followers_url":"https://api.github.com/users/paravoid/followers","following_url":"https://api.github.com/users/paravoid/following{/other_user}","gists_url":"https://api.github.com/users/paravoid/gists{/gist_id}","starred_url":"https://api.github.com/users/paravoid/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/paravoid/subscriptions","organizations_url":"https://api.github.com/users/paravoid/orgs","repos_url":"https://api.github.com/users/paravoid/repos","events_url":"https://api.github.com/users/paravoid/events{/privacy}","received_events_url":"https://api.github.com/users/paravoid/received_events","type":"User","site_admin":false},"created_at":"2017-04-05T02:43:44Z","updated_at":"2017-04-05T02:43:44Z","body":"Sorry for the late reply. I think in the short-term `KillMode=mixed` in the unit would work, but I definitely still think that the signal handlers should be cleaned up as described above.\r\n\r\nThat said, I'm currently unable to reproduce this bug anymore and I'm completely unsure why! I've tried reproducing it both with systemd and like I did before, with `pkill -f` and everything stops immediately. I still have the same collectors and handlers as before. This may be a race, but I'm not sure why the race always resulted in a failure before and always in success now; perhaps a collector suddenly became more responsive or something…"}}
{"actor":{"display_login":"paravoid"}}