Repository: chaoss/grimoirelab-perceval (language: python)

Issue:
Supybot Backend
# Overview

When running `perceval supybot` I receive a parse error saying a date is expected on line one.

## Further details

The exact output of the command is below:

```bash
$ perceval supybot ritfoss ./supybot/logs/ChannelLogger/freenode/#rit-foss/
[2021-01-12 11:58:22,013] - Sir Perceval is on his quest.
[2021-01-12 11:58:22,016] - Fetching messages of 'ritfoss' from 1970-01-01 00:00:00+00:00
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/perceval/backends/core/supybot.py", line 207, in parse_supybot_log
    for message in parser.parse():
  File "/usr/local/lib/python3.7/dist-packages/perceval/backends/core/supybot.py", line 366, in parse
    ts, msg = self._parse_supybot_timestamp(line)
  File "/usr/local/lib/python3.7/dist-packages/perceval/backends/core/supybot.py", line 387, in _parse_supybot_timestamp
    raise ParseError(cause=msg)
perceval.errors.ParseError: date expected on line 1

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/perceval/backend.py", line 618, in run
    for item in big.items:
  File "/usr/local/lib/python3.7/dist-packages/perceval/backend.py", line 794, in __fetch
    raise e
  File "/usr/local/lib/python3.7/dist-packages/perceval/backend.py", line 788, in __fetch
    for item in items:
  File "/usr/local/lib/python3.7/dist-packages/perceval/backend.py", line 226, in fetch
    for item in self.fetch_items(category, **kwargs):
  File "/usr/local/lib/python3.7/dist-packages/perceval/backends/core/supybot.py", line 118, in fetch_items
    for message in self.parse_supybot_log(archive):
  File "/usr/local/lib/python3.7/dist-packages/perceval/backends/core/supybot.py", line 211, in parse_supybot_log
    raise ParseError(cause=cause)
perceval.errors.ParseError: file: ./supybot/logs/ChannelLogger/freenode/#rit-foss/#rit-foss.log; reason: date expected on line 1

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/bin/perceval", line 169, in <module>
    main()
  File "/usr/local/bin/perceval", line 115, in main
    cmd.run()
  File "/usr/local/lib/python3.7/dist-packages/perceval/backend.py", line 630, in run
    raise RuntimeError(str(e))
RuntimeError: file: ./supybot/logs/ChannelLogger/freenode/#rit-foss/#rit-foss.log; reason: date expected on line 1
```

However, the log file seems to be formatted correctly with a datetime at the beginning of each line as shown below:

```bash
$ cat ./supybot/logs/ChannelLogger/freenode/#rit-foss/#rit-foss.log
2021-01-12T11:28:19  *** grimoire_bot <grimoire_bot!~limnoria@45.55.49.14> has joined #rit-foss
2021-01-12T11:29:41  <nolski> test
2021-01-12T11:29:41  <xbot1313> Test Case Passed!
```


Discussion / hints:
I've had a look at the tests, and I see that the problem here is that the fact that the timezone is missing is considered as a failure. I assume that instead of being it a bug in the code, the file format of the log file is not correctly formed.

@Nolski to solve your problem, you should add timezone information to your logs. For instance by adding "+0000" or whatever timezone you would like to use to your log file, as below. This should be easily be doable with a small script.

$ cat ./supybot/logs/ChannelLogger/freenode/#rit-foss/#rit-foss.log
2021-01-12T11:28:19+0000  *** grimoire_bot <grimoire_bot!~limnoria@45.55.49.14> has joined #rit-foss
2021-01-12T11:29:41+0000  <nolski> test
2021-01-12T11:29:41+0000  <xbot1313> Test Case Passed!
@gregoriorobles Given that this is the log that supybot generates, it would be worthwhile to have perceval conform to that format right? I'm curious if other grimoire users are having issues with the supybot integration.
@Nolski I am not a core developer of perceval. If @sduenas or any other core developer of perceval are positive about what you propose, I could implement it.
For what it's worth, these logs are generated by a bot running [Limnoria](https://github.com/ProgVal/Limnoria) which is the successor to Supybot as Supybot has been deprecated

Fix patch:
diff --git a/perceval/backends/core/supybot.py b/perceval/backends/core/supybot.py
index 58362b7f9..5f5317df0 100644
--- a/perceval/backends/core/supybot.py
+++ b/perceval/backends/core/supybot.py
@@ -64,7 +64,7 @@ class Supybot(Backend):
     :param tag: label used to mark the data
     :param archive: archive to store/retrieve items
     """
-    version = '0.9.0'
+    version = '0.10.0'
 
     CATEGORIES = [CATEGORY_MESSAGE]
 
@@ -314,7 +314,7 @@ class SupybotParser:
 
     :param stream: an iterator which produces Supybot log lines
     """
-    TIMESTAMP_PATTERN = r"""^(?P<ts>\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}[\+\-]\d{4})\s\s
+    TIMESTAMP_PATTERN = r"""^(?P<ts>\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}[\+\-]?\d{0,4})\s\s
                         (?P<msg>.+)$
                         """
     COMMENT_PATTERN = r"^<(?P<nick>(.*?)(!.*)?)>\s(?P<body>.+)$"


Test patch:
diff --git a/tests/data/supybot/supybot_date_without_tz.log b/tests/data/supybot/supybot_date_without_tz.log
new file mode 100644
index 000000000..0e9e9ba88
--- /dev/null
+++ b/tests/data/supybot/supybot_date_without_tz.log
@@ -0,0 +1,3 @@
+2021-01-12T11:28:19  *** grimoire_bot <grimoire_bot!~limnoria@45.55.49.14> has joined #rit-foss
+2021-01-12T11:29:41  <nolski> test
+2021-01-12T11:29:41  <xbot1313> Test Case Passed!
diff --git a/tests/test_supybot.py b/tests/test_supybot.py
index c59bd4463..428794f4c 100644
--- a/tests/test_supybot.py
+++ b/tests/test_supybot.py
@@ -191,6 +191,34 @@ def test_parse_supybot_log(self):
         self.assertEqual(msg['nick'], 'gregaf')
         self.assertEqual(msg['body'], "but I may be wrong or debugging at the wrong level...")
 
+    def test_parse_supybot_without_tz_log(self):
+        """Test whether it parses a log without timezone information"""
+
+        # Empty lines and empty comment lines are ignored
+        messages = Supybot.parse_supybot_log(os.path.join(os.path.dirname(os.path.abspath(__file__)),
+                                                          'data/supybot/supybot_date_without_tz.log'))
+        messages = [m for m in messages]
+
+        self.assertEqual(len(messages), 3)
+
+        msg = messages[0]
+        self.assertEqual(msg['timestamp'], '2021-01-12T11:28:19')
+        self.assertEqual(msg['type'], SupybotParser.TSERVER)
+        self.assertEqual(msg['nick'], 'grimoire_bot')
+        self.assertEqual(msg['body'], "grimoire_bot <grimoire_bot!~limnoria@45.55.49.14> has joined #rit-foss")
+
+        msg = messages[1]
+        self.assertEqual(msg['timestamp'], '2021-01-12T11:29:41')
+        self.assertEqual(msg['type'], SupybotParser.TCOMMENT)
+        self.assertEqual(msg['nick'], 'nolski')
+        self.assertEqual(msg['body'], "test")
+
+        msg = messages[-1]
+        self.assertEqual(msg['timestamp'], '2021-01-12T11:29:41')
+        self.assertEqual(msg['type'], SupybotParser.TCOMMENT)
+        self.assertEqual(msg['nick'], 'xbot1313')
+        self.assertEqual(msg['body'], "Test Case Passed!")
+
     def test_parse_supybot_invalid_log(self):
         """Test whether it raises an exception when the log is invalid"""
 
@@ -325,6 +353,12 @@ def test_timestamp_pattern(self):
         self.assertEqual(m.group('ts'), "2016-06-28T14:18:55-0230")
         self.assertEqual(m.group('msg'), "Whatever I put here is a valid message    ")
 
+        # Timezone is missing
+        s = "2016-06-28T14:18:55  Even if timezone is missing it is valid"
+        m = pattern.match(s)
+        self.assertEqual(m.group('ts'), "2016-06-28T14:18:55")
+        self.assertEqual(m.group('msg'), "Even if timezone is missing it is valid")
+
         # These messages are not valid
 
         # The message starts with spaces
@@ -337,11 +371,6 @@ def test_timestamp_pattern(self):
         m = pattern.match(s)
         self.assertIsNone(m)
 
-        # Timezone is missing
-        s = "2016-06-28T14:18:55  <mg> Hello!"
-        m = pattern.match(s)
-        self.assertIsNone(m)
-
         # Timestamp order invalid
         s = "28-06-2016T14:18:55+0000  <mg> Hello!"
         m = pattern.match(s)