{"action":"created","issue":{"url":"https://api.github.com/repos/3Hren/blackhole/issues/58","labels_url":"https://api.github.com/repos/3Hren/blackhole/issues/58/labels{/name}","comments_url":"https://api.github.com/repos/3Hren/blackhole/issues/58/comments","events_url":"https://api.github.com/repos/3Hren/blackhole/issues/58/events","html_url":"https://github.com/3Hren/blackhole/issues/58","id":97575652,"number":58,"title":"files sink doesn't always rotate logs","user":{"login":"bioothod","id":1847575,"avatar_url":"https://avatars.githubusercontent.com/u/1847575?v=3","gravatar_id":"","url":"https://api.github.com/users/bioothod","html_url":"https://github.com/bioothod","followers_url":"https://api.github.com/users/bioothod/followers","following_url":"https://api.github.com/users/bioothod/following{/other_user}","gists_url":"https://api.github.com/users/bioothod/gists{/gist_id}","starred_url":"https://api.github.com/users/bioothod/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bioothod/subscriptions","organizations_url":"https://api.github.com/users/bioothod/orgs","repos_url":"https://api.github.com/users/bioothod/repos","events_url":"https://api.github.com/users/bioothod/events{/privacy}","received_events_url":"https://api.github.com/users/bioothod/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":18,"created_at":"2015-07-27T23:02:43Z","updated_at":"2015-08-04T10:08:45Z","closed_at":null,"body":"We frequently see this issue in elliptics:\r\n\r\n`# ls -l /proc/19808/fd/ | grep log\r\nl-wx------ 1 root root 64 Jul 28 01:49 3 -> /home/admin/elliptics/log/ioserv.log-2015.07.22-1437535502 (deleted)\r\n`\r\n\r\nioserv.log - elliptics log file - was moved by logrotate 6 days ago, but blackhole didn't notice that and didn't reopen logfile.\r\nHere is appropriate config section:\r\n```javascript\r\n        \"logger\": {\r\n                \"frontends\": [\r\n                        {\r\n                                \"formatter\": {\r\n                                        \"type\": \"string\",\r\n                                        \"pattern\": \"%(timestamp)s %(request_id)s/%(lwp)s/%(pid)s %(severity)s: %(message)s %(...L)s\"\r\n                                },\r\n                                \"sink\": {\r\n                                        \"type\": \"files\",\r\n                                        \"path\": \"/home/admin/elliptics/log/ioserv.log\",\r\n                                        \"autoflush\": true,\r\n                                        \"rotation\": {\r\n                                                \"move\": 0\r\n                                        }\r\n                                }\r\n                        }\r\n                ],\r\n                \"level\": \"info\"\r\n        },\r\n```\r\n\r\nWe use blackhole 0.2 if that matters. Rotation changed a little bit - there were introduced additional checks which might explain why 'size' rotation doesn't work in 0.2, but common 'move' logic is the same afaics.\r\n\r\nIt doesn't happen all the time, but yet quite frequently."},"comment":{"url":"https://api.github.com/repos/3Hren/blackhole/issues/comments/127554222","html_url":"https://github.com/3Hren/blackhole/issues/58#issuecomment-127554222","issue_url":"https://api.github.com/repos/3Hren/blackhole/issues/58","id":127554222,"user":{"login":"bioothod","id":1847575,"avatar_url":"https://avatars.githubusercontent.com/u/1847575?v=3","gravatar_id":"","url":"https://api.github.com/users/bioothod","html_url":"https://github.com/bioothod","followers_url":"https://api.github.com/users/bioothod/followers","following_url":"https://api.github.com/users/bioothod/following{/other_user}","gists_url":"https://api.github.com/users/bioothod/gists{/gist_id}","starred_url":"https://api.github.com/users/bioothod/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bioothod/subscriptions","organizations_url":"https://api.github.com/users/bioothod/orgs","repos_url":"https://api.github.com/users/bioothod/repos","events_url":"https://api.github.com/users/bioothod/events{/privacy}","received_events_url":"https://api.github.com/users/bioothod/received_events","type":"User","site_admin":false},"created_at":"2015-08-04T10:08:45Z","updated_at":"2015-08-04T10:08:45Z","body":"Looks like its normal elliptics log message except that some python stuff (probably gdb-related).\r\nIt stuck in write call, buffer size looks like 175 bytes.\r\nLog file does contain that line.\r\n\r\nI didn't find `srd::basic_filebuf` pointer though.\r\nNB I've sent you a mail with core file URL and elliptics binary\r\n\r\n```\r\n#1  0x00007efce54c3136 in (anonymous namespace)::xwrite (__fd=3,\r\n    __s=0x7efcc8815050 \"2015-08-04 10:39:29.633711 \", '0' <repeats 16 times>, \"/20718/20713 INFO: backend_control: received BACKEND_CONTROL: backend_id: 13, command: 2, state: addr:57587 'backend_id': 13\\nime: 273 usecs, err: 0. \\n\"..., __n=175) at basic_file.cc:121\r\n#2  0x00007efce54fb35f in std::basic_filebuf<char, std::char_traits<char> >::_M_convert_to_external (this=this@entry=0xe49c78,\r\n    __ibuf=0x7efcc8815050 \"2015-08-04 10:39:29.633711 \", '0' <repeats 16 times>, \"/20718/20713 INFO: backend_control: received BACKEND_CONTROL: backend_id: 13, command: 2, state: addr:57587 'backend_id': 13\\nime: 273 usecs, err: 0. \\n\"..., __ilen=175)\r\n    at /home/packages/gcc/4.7/w/gcc-4.7-4.7.2/build/x86_64-linux-gnu/libstdc++-v3/include/bits/fstream.tcc:523\r\n#3  0x00007efce54fbc43 in std::basic_filebuf<char, std::char_traits<char> >::overflow (this=0xe49c78, __c=-1)\r\n    at /home/packages/gcc/4.7/w/gcc-4.7-4.7.2/build/x86_64-linux-gnu/libstdc++-v3/include/bits/fstream.tcc:450\r\n#4  0x00007efce54f974f in sync (this=<optimized out>) at /home/packages/gcc/4.7/w/gcc-4.7-4.7.2/build/x86_64-linux-gnu/libstdc++-v3/include/bits/fstream.tcc:902\r\n#5  std::basic_filebuf<char, std::char_traits<char> >::sync (this=<optimized out>)\r\n    at /home/packages/gcc/4.7/w/gcc-4.7-4.7.2/build/x86_64-linux-gnu/libstdc++-v3/include/bits/fstream.tcc:894\r\n#6  0x00007efce54dc00e in pubsync (this=<optimized out>) at /home/packages/gcc/4.7/w/gcc-4.7-4.7.2/build/x86_64-linux-gnu/libstdc++-v3/include/streambuf:269\r\n#7  std::ostream::flush (this=0xe49c70) at /home/packages/gcc/4.7/w/gcc-4.7-4.7.2/build/x86_64-linux-gnu/libstdc++-v3/include/bits/ostream.tcc:221\r\n#8  0x00007efce6e56db0 in flush (this=<optimized out>) at /usr/include/blackhole/sink/files/backend.hpp:93\r\n#9  flush (this=<optimized out>) at /usr/include/blackhole/sink/files/flusher.hpp:21\r\n#10 handle (message=\r\n    \"2015-08-04 10:39:29.633711 \", '0' <repeats 16 times>, \"/20718/20713 INFO: backend_control: received BACKEND_CONTROL: backend_id: 13, command: 2, state: addr:57587 'backend_id': 13\", this=0xe49c68) at /usr/include/blackhole/sink/files.hpp:67\r\n#11 blackhole::sink::files_t<blackhole::sink::files::boost_backend_t, blackhole::sink::rotator_t<blackhole::sink::files::boost_backend_t, blackhole::sink::rotation::watcher::move_t, blackhole::sink::rotation::timer_t> >::consume (this=<optimized out>, message=\r\nPython Exception <type 'exceptions.IndexError'> list index out of range:\r\n    \"2015-08-04 10:39:29.633711 \", '0' <repeats 16 times>, \"/20718/20713 INFO: backend_control: received BACKEND_CONTROL: backend_id: 13, command: 2, state: addr:57587 'backend_id': 13\", attributes=std::unordered_map with 8 elements) at /usr/include/blackhole/sink/files.hpp:120\r\n```"}}