We are currently solving the following issue within our repository. Here is the issue text:
--- BEGIN ISSUE ---
Overlapping in json logging
Hello,

Yesterday, I've updated to the newest version of cowrie and found that json logs regulary become invalid because of overlapping messages:

{"eventid": "cowrie.direct-tcpip.data", "timestamp": "2016-08-25T19:45:14.966466Z", "sensor": "redacted", "system": "SSHChannel None (13) on SSHService ssh-connection on HoneyPotSSHTransport,65,193.169.53.173", "isError": 0, "src_ip": "redacted", "session": "6649575c", "dst_port": 443, "dst_ip": "redacted", "data": "'\x16\x03\x01\x01x\x01\x00\x01t\x03\x03W\xbfKf\x82v^\x9e\x7f\x15\t\x08+o\x13(9\x05\xcd4\"\xebk}\xcb\xa00|\xce\x9e\x1do\x00\x00\xca\xc00\xc0,\xc0(\xc0$\xc0\x14\xc0\n\xc0\"\xc0!\x00\xa3\x00\x9f\x00k\x00j\x009\x008\x00\x88\x00\x87\xc0\x19\xc0 \x00\xa7\x00m\x00:\x00\x89\xc02\xc0.\xc0_\xc0&\xc0\x0f\xc0\x05\x00\x9d\x00=\x005\x00\x84\xc0\x12\xc0\x08\xc0\x1c\xc0\x1b\x00\x16\x00\x13\xc0\x17\xc0\x1a\x00\x1b\xc0\r\xc0\x03\x00\n\xc0/\xc0+\xc0\'\xc0#\xc0\x13\xc0\t\xc0\x1f\xc0\x1e\x00\xa2\x00\x9e\x00g\x00@\x003\x002\x00\x9a\x00\x99\x00E\x00D\xc0\x18\xc0\x1d\x00\xa6\x00l\x004\x00\x9b\x00F\xc01\xc0-\xc0)\xc0%\xc0\x0e\xc0\x04\x00\x9c\x00<\x00/\x00\x96\x00A\x00\x07\xc0\x11\xc0\x07\xc0\x16\x00\x18\xc0\x0c\xc0\x02\x00\x05\x00\x04\x00\x15\x00\x12\x00\x1a\x00\t\x00\x14\x00\x11\x00\x19\x00\x08\x00\x06\x00\x17\x00\x03\x00\xff\x01\x00\x00\x81\x00\x00\x00\x12\x00\x10\x00\x00\rwww.google.se\x00\x0b\x00\x04\x03\x00\x01\x02\x00\n\x004\x002\x00\x0e\x00\r\x00\x19\x00\x0b\x00\x0c\x00\x18\x00\t\x00\n\x00\x16\x00\x17\x00\x08\x00\x06\x00\x07\x00\x14\x00\x15\x00\x04\x00\x05\x00\x12\x00\x13\x00\x01\x00\x02\x00\x03\x00\x0f\x00\x10\x00\x11\x00\r\x00\"\x00 \x06\x01\x06\x02\x06\x03\x05\x01\x05\x02\x05\x03\x04\x01\x04\x02\x04\x03\x03\x01\x03\x02\x03\x03\x02\x01\x02\x02\x02\x03\x01\x01\x00\x0f\x00\x01\x01'", "message": "direct-tcp forward to 173.194.222.94:443 with data '\x16\x03\x01\x01x\x01\x00\x01t\x03\x03W\xbfKf\x82v^\x9e\x7f\x15\t\x08+o\x13(9\x05\xcd4\"\xebk}\xcb\xa00|\xce\x9e\x1do\x00\x00\xca\xc00\xc0,\xc0(\xc0$\xc0\x14\xc0\n\xc0\"\xc0!\x00\xa3\x00\x9f\x00k\x00j\x009\x008\x00\x88\x00\x87\xc0\x19\xc0 \x00\xa7\x00m\x00:\x00\x89\xc02\xc0.\xc0_\xc0&\xc0\x0f\xc0\x05\x00\x9d\x00=\x005\x00\x84\xc0\x12\xc0\x08\xc0\x1c\xc0\x1b\x00\x16\x00\x13\xc0\x17\xc0\x1a\x00\x1b\xc0\r\xc0\x03\x00\n\xc0/\xc0+\xc0\'\xc0#\xc0\x13\xc0\t\xc0\x1f\xc0\x1e\x00\xa2\x00\x9e\x00g\x00@\x003\x002\x00\x9a\x00\x99\x00E\x00D\xc0\x18\xc0\x1d\x00\xa6\x00l\x004\x00\x9b\x00F\xc01\xc0-\xc0)\xc0%\xc0\x0e\xc0\x04\x00\x9c\x00<\x00/\x00\x96\x00A\x00\x07\xc0\x11\xc0\x07\xc0\x16\x00\x18\xc0\x0c\xc0\x02\x00\x05\x00\x04\x00\x15\x00\x12\x00\x1a\x00\t\x00\x14\x00\x11\x00\x19\x00\x08\x00\x06\x00\x17\x00\x03\x00\xff\x01\x00\x00\x81\x00\x00\x00\x12\x00\x10\x00\x00\rwww.google.se\x00\x0b\x00\x04\x03\x00\x01\x02\x00\n\x004\x002\x00\x0e\x00\r\x00\x19\x00\x0b\x00\x0c\x00\x18\x00\t\x00\n\x00\x16\x00\x17\x00\x08\x00\x06\x00\x07\x00\x14\x00\x15\x00\x04\x00\x05\x00\x12\x00\x13\x00\x01\x00\x02\x00\x03\x00\x0f\x00\x10\x00\x11\x00\r{"eventid": "cowrie.direct-tcpip.data", "timestamp": "2016-08-25T19:45:14.966466Z", "sensor": "redacted", "system": "SSHChannel None (13) on SSHService ssh-connection on HoneyPotSSHTransport,65,193.169.53.1{"eventid": "cowrie.direct-tcpip.request", "timestamp": "2016-08-25T19:45:24.508664Z", "session": "a0c671d3", "src_port": 5556, "message": "direct-tcp connection request to 98.138.112.32:25 from localhost:5556", "system": "SSHService ssh-connection on HoneyPotSSHTransport,62,193.169.52.222", "isError": 0, "src_ip": "redacted", "dst_port": 25, "dst_ip": "redacted", "sensor": "redacted"} 

If you look carefully, there is the second log message inserted right into the first ( "\x11\x00\r{"eventid":" ) and the third is inserted into the second one: " 65,193.169.53.1{"eventid":  "

The only suspicious thing in logs is presence of tracebacks that repeat pretty often:

2016-08-25T22:29:08+0300 [SSHChannel None (2) on SSHService ssh-connection on HoneyPotSSHTransport,65,censored] sending close 2
2016-08-25T22:29:24+0300 [twisted.internet.defer#critical] Unhandled error in Deferred:

Traceback (most recent call last):
Failure: twisted.internet.error.ConnectionDone: Connection was closed cleanly.
...

2016-08-25T22:28:52+0300 [StripCrTelnetTransport,221,censored] Warning: state changed and new state returned
2016-08-25T22:29:01+0300 [twisted.internet.defer#critical] Unhandled error in Deferred:

Traceback (most recent call last):
Failure: twisted.conch.telnet.OptionRefused: twisted.conch.telnet.OptionRefused:'\x03'

Any ideas?


--- END ISSUE ---

Below are some code segments, each from a relevant file. One or more of these files may contain bugs.
--- BEGIN FILES ---
Path: `cowrie/output/jsonlog.py`
Content:
```
1 # Copyright (c) 2015 Michel Oosterhof <michel@oosterhof.net>
2 # All rights reserved.
3 #
4 # Redistribution and use in source and binary forms, with or without
5 # modification, are permitted provided that the following conditions
6 # are met:
7 #
8 # 1. Redistributions of source code must retain the above copyright
9 #    notice, this list of conditions and the following disclaimer.
10 # 2. Redistributions in binary form must reproduce the above copyright
11 #    notice, this list of conditions and the following disclaimer in the
12 #    documentation and/or other materials provided with the distribution.
13 # 3. The names of the author(s) may not be used to endorse or promote
14 #    products derived from this software without specific prior written
15 #    permission.
16 #
17 # THIS SOFTWARE IS PROVIDED BY THE AUTHORS ``AS IS'' AND ANY EXPRESS OR
18 # IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
19 # OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.
20 # IN NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY DIRECT, INDIRECT,
21 # INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING,
22 # BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
23 # LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
24 # AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
25 # OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
26 # OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
27 # SUCH DAMAGE.
28 
29 """
30 Docstring
31 """
32 
33 import json
34 import os
35 
36 import twisted.python.logfile
37 
38 import cowrie.core.output
39 
40 class Output(cowrie.core.output.Output):
41     """
42     Docstring class
43     """
44 
45     def __init__(self, cfg):
46         cowrie.core.output.Output.__init__(self, cfg)
47         fn = cfg.get('output_jsonlog', 'logfile')
48         dirs = os.path.dirname(fn)
49         base = os.path.basename(fn)
50         self.outfile = twisted.python.logfile.DailyLogFile(base, dirs, defaultMode=0o664)
51 
52 
53     def start(self):
54         """
55         """
56         pass
57 
58 
59     def stop(self):
60         """
61         """
62         self.outfile.flush()
63 
64 
65     def write(self, logentry):
66         """
67         """
68         for i in list(logentry.keys()):
69             # Remove twisted 15 legacy keys
70             if i.startswith('log_'):
71                 del logentry[i]
72         json.dump(logentry, self.outfile)
73         self.outfile.write('\n')
74         self.outfile.flush()
75 
76
```
--- END FILES ---

Please first localize the bug based on the issue statement, and then generate a patch according to the `git diff` format fenced by three backticks.

Here is an example:

```diff
diff --git a/examples/server_async.py b/examples/server_async.py
--- a/examples/server_async.py
+++ b/examples/server_async.py
@@ -313,4 +313,4 @@
 
 
 if __name__ == "__main__":
-    asyncio.run(run_async_server("."), debug=True)
+    asyncio.run(run_async_server(), debug=True)
diff --git a/examples/server_sync.py b/examples/server_sync.py
--- a/examples/server_sync.py
+++ b/examples/server_sync.py
@@ -313,5 +313,5 @@
 
 
 if __name__ == "__main__":
-    server = run_sync_server(".")
+    server = run_sync_server()
     server.shutdown()

```

diff --git a/cowrie/output/jsonlog.py b/cowrie/output/jsonlog.py
--- a/cowrie/output/jsonlog.py
+++ b/cowrie/output/jsonlog.py
@@ -32,7 +32,10 @@
 
 import json
 import os
+import Queue
+import threading
 
+from twisted.python import log
 import twisted.python.logfile
 
 import cowrie.core.output
@@ -47,8 +50,21 @@
         fn = cfg.get('output_jsonlog', 'logfile')
         dirs = os.path.dirname(fn)
         base = os.path.basename(fn)
+
+        # create the log queue with a default buffer size if none is specified in
+        # the log file.
+        buffer_size = 10000
+        if cfg.has_option('output_jsonlog', 'buffer_size'):
+            buffer_size = int(cfg.get('output_jsonlog', 'buffer_size'))
+        self._log_writer_queue = Queue.Queue(maxsize=buffer_size)
+
+        # allocate the output file
         self.outfile = twisted.python.logfile.DailyLogFile(base, dirs, defaultMode=0o664)
 
+        # start the log writer thread
+        self._log_writer_thread = threading.Thread(target=self._write_log)
+        self._log_writer_thread.daemon = True
+        self._log_writer_thread.start()
 
     def start(self):
         """
@@ -59,6 +75,7 @@
     def stop(self):
         """
         """
+        self._log_queue.join()
         self.outfile.flush()
 
 
@@ -69,7 +86,26 @@
             # Remove twisted 15 legacy keys
             if i.startswith('log_'):
                 del logentry[i]
-        json.dump(logentry, self.outfile)
-        self.outfile.write('\n')
-        self.outfile.flush()
+
+        # TODO: There's a possibility that the queue is full when we do this put, which means
+        # we'll lose the log item. We specifically use put_nowait so in that case it doesn't
+        # block the main writer thread.
+        try:
+            self._log_writer_queue.put_nowait(json.dumps(logentry))
+        except Queue.Full:
+            log.err('Could not queue jsonlog item. Consider increasing buffer_size in [output_jsonlog] of your cowrie configuration')
+
+    def _write_log(self):
+        # there's a probability of hitting IO errors while attempting to write
+        # for various reasons (for example, the disk is full). So, regardless
+        # of what happens during the write, we always mark the queue item as done
+        # so self.stop() can properly join on any remaining items.
+        while True:
+            item = self._log_writer_queue.get()
+            try:
+                self.outfile.write(item)
+                self.outfile.write('\n')
+                self.outfile.flush()
+            finally:
+                self._log_writer_queue.task_done()

{"golden_diff": "diff --git a/cowrie/output/jsonlog.py b/cowrie/output/jsonlog.py\n--- a/cowrie/output/jsonlog.py\n+++ b/cowrie/output/jsonlog.py\n@@ -32,7 +32,10 @@\n \n import json\n import os\n+import Queue\n+import threading\n \n+from twisted.python import log\n import twisted.python.logfile\n \n import cowrie.core.output\n@@ -47,8 +50,21 @@\n         fn = cfg.get('output_jsonlog', 'logfile')\n         dirs = os.path.dirname(fn)\n         base = os.path.basename(fn)\n+\n+        # create the log queue with a default buffer size if none is specified in\n+        # the log file.\n+        buffer_size = 10000\n+        if cfg.has_option('output_jsonlog', 'buffer_size'):\n+            buffer_size = int(cfg.get('output_jsonlog', 'buffer_size'))\n+        self._log_writer_queue = Queue.Queue(maxsize=buffer_size)\n+\n+        # allocate the output file\n         self.outfile = twisted.python.logfile.DailyLogFile(base, dirs, defaultMode=0o664)\n \n+        # start the log writer thread\n+        self._log_writer_thread = threading.Thread(target=self._write_log)\n+        self._log_writer_thread.daemon = True\n+        self._log_writer_thread.start()\n \n     def start(self):\n         \"\"\"\n@@ -59,6 +75,7 @@\n     def stop(self):\n         \"\"\"\n         \"\"\"\n+        self._log_queue.join()\n         self.outfile.flush()\n \n \n@@ -69,7 +86,26 @@\n             # Remove twisted 15 legacy keys\n             if i.startswith('log_'):\n                 del logentry[i]\n-        json.dump(logentry, self.outfile)\n-        self.outfile.write('\\n')\n-        self.outfile.flush()\n+\n+        # TODO: There's a possibility that the queue is full when we do this put, which means\n+        # we'll lose the log item. We specifically use put_nowait so in that case it doesn't\n+        # block the main writer thread.\n+        try:\n+            self._log_writer_queue.put_nowait(json.dumps(logentry))\n+        except Queue.Full:\n+            log.err('Could not queue jsonlog item. Consider increasing buffer_size in [output_jsonlog] of your cowrie configuration')\n+\n+    def _write_log(self):\n+        # there's a probability of hitting IO errors while attempting to write\n+        # for various reasons (for example, the disk is full). So, regardless\n+        # of what happens during the write, we always mark the queue item as done\n+        # so self.stop() can properly join on any remaining items.\n+        while True:\n+            item = self._log_writer_queue.get()\n+            try:\n+                self.outfile.write(item)\n+                self.outfile.write('\\n')\n+                self.outfile.flush()\n+            finally:\n+                self._log_writer_queue.task_done()\n", "issue": "Overlapping in json logging\nHello,\n\nYesterday, I've updated to the newest version of cowrie and found that json logs regulary become invalid because of overlapping messages:\n\n{\"eventid\": \"cowrie.direct-tcpip.data\", \"timestamp\": \"2016-08-25T19:45:14.966466Z\", \"sensor\": \"redacted\", \"system\": \"SSHChannel None (13) on SSHService ssh-connection on HoneyPotSSHTransport,65,193.169.53.173\", \"isError\": 0, \"src_ip\": \"redacted\", \"session\": \"6649575c\", \"dst_port\": 443, \"dst_ip\": \"redacted\", \"data\": \"'\\x16\\x03\\x01\\x01x\\x01\\x00\\x01t\\x03\\x03W\\xbfKf\\x82v^\\x9e\\x7f\\x15\\t\\x08+o\\x13(9\\x05\\xcd4\\\"\\xebk}\\xcb\\xa00|\\xce\\x9e\\x1do\\x00\\x00\\xca\\xc00\\xc0,\\xc0(\\xc0$\\xc0\\x14\\xc0\\n\\xc0\\\"\\xc0!\\x00\\xa3\\x00\\x9f\\x00k\\x00j\\x009\\x008\\x00\\x88\\x00\\x87\\xc0\\x19\\xc0 \\x00\\xa7\\x00m\\x00:\\x00\\x89\\xc02\\xc0.\\xc0_\\xc0&\\xc0\\x0f\\xc0\\x05\\x00\\x9d\\x00=\\x005\\x00\\x84\\xc0\\x12\\xc0\\x08\\xc0\\x1c\\xc0\\x1b\\x00\\x16\\x00\\x13\\xc0\\x17\\xc0\\x1a\\x00\\x1b\\xc0\\r\\xc0\\x03\\x00\\n\\xc0/\\xc0+\\xc0\\'\\xc0#\\xc0\\x13\\xc0\\t\\xc0\\x1f\\xc0\\x1e\\x00\\xa2\\x00\\x9e\\x00g\\x00@\\x003\\x002\\x00\\x9a\\x00\\x99\\x00E\\x00D\\xc0\\x18\\xc0\\x1d\\x00\\xa6\\x00l\\x004\\x00\\x9b\\x00F\\xc01\\xc0-\\xc0)\\xc0%\\xc0\\x0e\\xc0\\x04\\x00\\x9c\\x00<\\x00/\\x00\\x96\\x00A\\x00\\x07\\xc0\\x11\\xc0\\x07\\xc0\\x16\\x00\\x18\\xc0\\x0c\\xc0\\x02\\x00\\x05\\x00\\x04\\x00\\x15\\x00\\x12\\x00\\x1a\\x00\\t\\x00\\x14\\x00\\x11\\x00\\x19\\x00\\x08\\x00\\x06\\x00\\x17\\x00\\x03\\x00\\xff\\x01\\x00\\x00\\x81\\x00\\x00\\x00\\x12\\x00\\x10\\x00\\x00\\rwww.google.se\\x00\\x0b\\x00\\x04\\x03\\x00\\x01\\x02\\x00\\n\\x004\\x002\\x00\\x0e\\x00\\r\\x00\\x19\\x00\\x0b\\x00\\x0c\\x00\\x18\\x00\\t\\x00\\n\\x00\\x16\\x00\\x17\\x00\\x08\\x00\\x06\\x00\\x07\\x00\\x14\\x00\\x15\\x00\\x04\\x00\\x05\\x00\\x12\\x00\\x13\\x00\\x01\\x00\\x02\\x00\\x03\\x00\\x0f\\x00\\x10\\x00\\x11\\x00\\r\\x00\\\"\\x00 \\x06\\x01\\x06\\x02\\x06\\x03\\x05\\x01\\x05\\x02\\x05\\x03\\x04\\x01\\x04\\x02\\x04\\x03\\x03\\x01\\x03\\x02\\x03\\x03\\x02\\x01\\x02\\x02\\x02\\x03\\x01\\x01\\x00\\x0f\\x00\\x01\\x01'\", \"message\": \"direct-tcp forward to 173.194.222.94:443 with data '\\x16\\x03\\x01\\x01x\\x01\\x00\\x01t\\x03\\x03W\\xbfKf\\x82v^\\x9e\\x7f\\x15\\t\\x08+o\\x13(9\\x05\\xcd4\\\"\\xebk}\\xcb\\xa00|\\xce\\x9e\\x1do\\x00\\x00\\xca\\xc00\\xc0,\\xc0(\\xc0$\\xc0\\x14\\xc0\\n\\xc0\\\"\\xc0!\\x00\\xa3\\x00\\x9f\\x00k\\x00j\\x009\\x008\\x00\\x88\\x00\\x87\\xc0\\x19\\xc0 \\x00\\xa7\\x00m\\x00:\\x00\\x89\\xc02\\xc0.\\xc0_\\xc0&\\xc0\\x0f\\xc0\\x05\\x00\\x9d\\x00=\\x005\\x00\\x84\\xc0\\x12\\xc0\\x08\\xc0\\x1c\\xc0\\x1b\\x00\\x16\\x00\\x13\\xc0\\x17\\xc0\\x1a\\x00\\x1b\\xc0\\r\\xc0\\x03\\x00\\n\\xc0/\\xc0+\\xc0\\'\\xc0#\\xc0\\x13\\xc0\\t\\xc0\\x1f\\xc0\\x1e\\x00\\xa2\\x00\\x9e\\x00g\\x00@\\x003\\x002\\x00\\x9a\\x00\\x99\\x00E\\x00D\\xc0\\x18\\xc0\\x1d\\x00\\xa6\\x00l\\x004\\x00\\x9b\\x00F\\xc01\\xc0-\\xc0)\\xc0%\\xc0\\x0e\\xc0\\x04\\x00\\x9c\\x00<\\x00/\\x00\\x96\\x00A\\x00\\x07\\xc0\\x11\\xc0\\x07\\xc0\\x16\\x00\\x18\\xc0\\x0c\\xc0\\x02\\x00\\x05\\x00\\x04\\x00\\x15\\x00\\x12\\x00\\x1a\\x00\\t\\x00\\x14\\x00\\x11\\x00\\x19\\x00\\x08\\x00\\x06\\x00\\x17\\x00\\x03\\x00\\xff\\x01\\x00\\x00\\x81\\x00\\x00\\x00\\x12\\x00\\x10\\x00\\x00\\rwww.google.se\\x00\\x0b\\x00\\x04\\x03\\x00\\x01\\x02\\x00\\n\\x004\\x002\\x00\\x0e\\x00\\r\\x00\\x19\\x00\\x0b\\x00\\x0c\\x00\\x18\\x00\\t\\x00\\n\\x00\\x16\\x00\\x17\\x00\\x08\\x00\\x06\\x00\\x07\\x00\\x14\\x00\\x15\\x00\\x04\\x00\\x05\\x00\\x12\\x00\\x13\\x00\\x01\\x00\\x02\\x00\\x03\\x00\\x0f\\x00\\x10\\x00\\x11\\x00\\r{\"eventid\": \"cowrie.direct-tcpip.data\", \"timestamp\": \"2016-08-25T19:45:14.966466Z\", \"sensor\": \"redacted\", \"system\": \"SSHChannel None (13) on SSHService ssh-connection on HoneyPotSSHTransport,65,193.169.53.1{\"eventid\": \"cowrie.direct-tcpip.request\", \"timestamp\": \"2016-08-25T19:45:24.508664Z\", \"session\": \"a0c671d3\", \"src_port\": 5556, \"message\": \"direct-tcp connection request to 98.138.112.32:25 from localhost:5556\", \"system\": \"SSHService ssh-connection on HoneyPotSSHTransport,62,193.169.52.222\", \"isError\": 0, \"src_ip\": \"redacted\", \"dst_port\": 25, \"dst_ip\": \"redacted\", \"sensor\": \"redacted\"} \n\nIf you look carefully, there is the second log message inserted right into the first ( \"\\x11\\x00\\r{\"eventid\":\" ) and the third is inserted into the second one: \" 65,193.169.53.1{\"eventid\":  \"\n\nThe only suspicious thing in logs is presence of tracebacks that repeat pretty often:\n\n2016-08-25T22:29:08+0300 [SSHChannel None (2) on SSHService ssh-connection on HoneyPotSSHTransport,65,censored] sending close 2\n2016-08-25T22:29:24+0300 [twisted.internet.defer#critical] Unhandled error in Deferred:\n\nTraceback (most recent call last):\nFailure: twisted.internet.error.ConnectionDone: Connection was closed cleanly.\n...\n\n2016-08-25T22:28:52+0300 [StripCrTelnetTransport,221,censored] Warning: state changed and new state returned\n2016-08-25T22:29:01+0300 [twisted.internet.defer#critical] Unhandled error in Deferred:\n\nTraceback (most recent call last):\nFailure: twisted.conch.telnet.OptionRefused: twisted.conch.telnet.OptionRefused:'\\x03'\n\nAny ideas?\n\n", "before_files": [{"content": "# Copyright (c) 2015 Michel Oosterhof <michel@oosterhof.net>\n# All rights reserved.\n#\n# Redistribution and use in source and binary forms, with or without\n# modification, are permitted provided that the following conditions\n# are met:\n#\n# 1. Redistributions of source code must retain the above copyright\n#    notice, this list of conditions and the following disclaimer.\n# 2. Redistributions in binary form must reproduce the above copyright\n#    notice, this list of conditions and the following disclaimer in the\n#    documentation and/or other materials provided with the distribution.\n# 3. The names of the author(s) may not be used to endorse or promote\n#    products derived from this software without specific prior written\n#    permission.\n#\n# THIS SOFTWARE IS PROVIDED BY THE AUTHORS ``AS IS'' AND ANY EXPRESS OR\n# IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES\n# OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.\n# IN NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY DIRECT, INDIRECT,\n# INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING,\n# BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;\n# LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED\n# AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,\n# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY\n# OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF\n# SUCH DAMAGE.\n\n\"\"\"\nDocstring\n\"\"\"\n\nimport json\nimport os\n\nimport twisted.python.logfile\n\nimport cowrie.core.output\n\nclass Output(cowrie.core.output.Output):\n    \"\"\"\n    Docstring class\n    \"\"\"\n\n    def __init__(self, cfg):\n        cowrie.core.output.Output.__init__(self, cfg)\n        fn = cfg.get('output_jsonlog', 'logfile')\n        dirs = os.path.dirname(fn)\n        base = os.path.basename(fn)\n        self.outfile = twisted.python.logfile.DailyLogFile(base, dirs, defaultMode=0o664)\n\n\n    def start(self):\n        \"\"\"\n        \"\"\"\n        pass\n\n\n    def stop(self):\n        \"\"\"\n        \"\"\"\n        self.outfile.flush()\n\n\n    def write(self, logentry):\n        \"\"\"\n        \"\"\"\n        for i in list(logentry.keys()):\n            # Remove twisted 15 legacy keys\n            if i.startswith('log_'):\n                del logentry[i]\n        json.dump(logentry, self.outfile)\n        self.outfile.write('\\n')\n        self.outfile.flush()\n\n", "path": "cowrie/output/jsonlog.py"}], "after_files": [{"content": "# Copyright (c) 2015 Michel Oosterhof <michel@oosterhof.net>\n# All rights reserved.\n#\n# Redistribution and use in source and binary forms, with or without\n# modification, are permitted provided that the following conditions\n# are met:\n#\n# 1. Redistributions of source code must retain the above copyright\n#    notice, this list of conditions and the following disclaimer.\n# 2. Redistributions in binary form must reproduce the above copyright\n#    notice, this list of conditions and the following disclaimer in the\n#    documentation and/or other materials provided with the distribution.\n# 3. The names of the author(s) may not be used to endorse or promote\n#    products derived from this software without specific prior written\n#    permission.\n#\n# THIS SOFTWARE IS PROVIDED BY THE AUTHORS ``AS IS'' AND ANY EXPRESS OR\n# IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES\n# OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.\n# IN NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY DIRECT, INDIRECT,\n# INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING,\n# BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;\n# LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED\n# AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,\n# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY\n# OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF\n# SUCH DAMAGE.\n\n\"\"\"\nDocstring\n\"\"\"\n\nimport json\nimport os\nimport Queue\nimport threading\n\nfrom twisted.python import log\nimport twisted.python.logfile\n\nimport cowrie.core.output\n\nclass Output(cowrie.core.output.Output):\n    \"\"\"\n    Docstring class\n    \"\"\"\n\n    def __init__(self, cfg):\n        cowrie.core.output.Output.__init__(self, cfg)\n        fn = cfg.get('output_jsonlog', 'logfile')\n        dirs = os.path.dirname(fn)\n        base = os.path.basename(fn)\n\n        # create the log queue with a default buffer size if none is specified in\n        # the log file.\n        buffer_size = 10000\n        if cfg.has_option('output_jsonlog', 'buffer_size'):\n            buffer_size = int(cfg.get('output_jsonlog', 'buffer_size'))\n        self._log_writer_queue = Queue.Queue(maxsize=buffer_size)\n\n        # allocate the output file\n        self.outfile = twisted.python.logfile.DailyLogFile(base, dirs, defaultMode=0o664)\n\n        # start the log writer thread\n        self._log_writer_thread = threading.Thread(target=self._write_log)\n        self._log_writer_thread.daemon = True\n        self._log_writer_thread.start()\n\n    def start(self):\n        \"\"\"\n        \"\"\"\n        pass\n\n\n    def stop(self):\n        \"\"\"\n        \"\"\"\n        self._log_queue.join()\n        self.outfile.flush()\n\n\n    def write(self, logentry):\n        \"\"\"\n        \"\"\"\n        for i in list(logentry.keys()):\n            # Remove twisted 15 legacy keys\n            if i.startswith('log_'):\n                del logentry[i]\n\n        # TODO: There's a possibility that the queue is full when we do this put, which means\n        # we'll lose the log item. We specifically use put_nowait so in that case it doesn't\n        # block the main writer thread.\n        try:\n            self._log_writer_queue.put_nowait(json.dumps(logentry))\n        except Queue.Full:\n            log.err('Could not queue jsonlog item. Consider increasing buffer_size in [output_jsonlog] of your cowrie configuration')\n\n    def _write_log(self):\n        # there's a probability of hitting IO errors while attempting to write\n        # for various reasons (for example, the disk is full). So, regardless\n        # of what happens during the write, we always mark the queue item as done\n        # so self.stop() can properly join on any remaining items.\n        while True:\n            item = self._log_writer_queue.get()\n            try:\n                self.outfile.write(item)\n                self.outfile.write('\\n')\n                self.outfile.flush()\n            finally:\n                self._log_writer_queue.task_done()\n\n", "path": "cowrie/output/jsonlog.py"}]}