# -*- encoding: UTF8 -*-
# Test harness for JobsCmdFilter.py

from __future__ import print_function

import sys
import unittest
import os
import io
import logging
import re
import sqlite3
sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))

from log2sql import Log2sql

python3 = sys.version_info[0] >= 3

if python3:
    from io import StringIO
else:
    from StringIO import StringIO

fileHeader = """CREATE DATABASE IF NOT EXISTS testdb;
USE testdb;
DROP TABLE IF EXISTS process;
CREATE TABLE process (processkey CHAR(32) NOT NULL, lineNumber INT NOT NULL, pid INT NOT NULL, startTime DATETIME NOT NULL,endTime DATETIME NULL, computedLapse FLOAT NULL,completedLapse FLOAT NULL, user TEXT NOT NULL, workspace TEXT NOT NULL, ip TEXT NOT NULL, app TEXT NOT NULL, cmd TEXT NOT NULL, args TEXT NULL, uCpu INT NULL, sCpu INT NULL, diskIn INT NULL, diskOut INT NULL, ipcIn INT NULL, ipcOut INT NULL, maxRss INT NULL, pageFaults INT NULL, rpcMsgsIn INT NULL, rpcMsgsOut INT NULL, rpcSizeIn INT NULL, rpcSizeOut INT NULL, rpcHimarkFwd INT NULL, rpcHimarkRev INT NULL, rpcSnd FLOAT NULL, rpcRcv FLOAT NULL, running INT NULL, error TEXT NULL, PRIMARY KEY (processkey, lineNumber));
DROP TABLE IF EXISTS tableUse;
CREATE TABLE tableUse (processkey CHAR(32) NOT NULL, lineNumber INT NOT NULL, tableName VARCHAR(255) NOT NULL, pagesIn INT NULL, pagesOut INT NULL, pagesCached INT NULL, readLocks INT NULL, writeLocks INT NULL, getRows INT NULL, posRows INT NULL, scanRows INT NULL, putRows int NULL, delRows INT NULL, totalReadWait INT NULL, totalReadHeld INT NULL, totalWriteWait INT NULL, totalWriteHeld INT NULL, maxReadWait INT NULL, maxReadHeld INT NULL, maxWriteWait INT NULL, maxWriteHeld INT NULL, peekCount INT NULL, totalPeekWait INT NULL, totalPeekHeld INT NULL, maxPeekWait  INT NULL, maxPeekHeld  INT NULL, PRIMARY KEY (processkey, lineNumber, tableName));
BEGIN TRANSACTION;
"""

class MyOptions():
    def __init__(self, dbname, logname, sql=False, verbosity=logging.DEBUG):
        self.dbname = dbname
        self.logname = logname
        self.sql = sql
        self.verbosity = verbosity
        self.interval = 10
        self.outlog = None

class TestLogParser(unittest.TestCase):

    def __init__(self, methodName='runTest'):
        super(TestLogParser, self).__init__(methodName=methodName)
        self.maxDiff = None

    def assertRegex(self, *args, **kwargs):
        if python3:
            return super(TestLogParser, self).assertRegex(*args, **kwargs)
        else:
            return super(TestLogParser, self).assertRegexpMatches(*args, **kwargs)

    def setUp(self):
        pass

    def tearDown(self):
        pass

    def runTestText(self, expected, input, longlines=False):
        optionsText = MyOptions("testdb", "")
        self.saved_stdoutput = StringIO()
        self.saved_stderr = StringIO()
        log2sql = Log2sql(optionsText, instream=StringIO(input), outstream=self.saved_stdoutput, errstream=self.saved_stderr)
        log2sql.processLog()
        actual = self.saved_stdoutput.getvalue()
        self.assertMultiLineEqual(fileHeader, actual[:len(fileHeader)])
        if not longlines:
            exp = "\n".join(sorted(expected.split("\n")))
            act = "\n".join(sorted(actual[len(fileHeader):].split("\n")))
            self.assertMultiLineEqual(exp, act)
        else:
            rest = actual[len(fileHeader):]
            for expline in expected.split("\n"):
                reLine = re.compile(expline.replace("(", "\("), re.MULTILINE)
                self.assertRegex(rest, reLine, re.MULTILINE)
        reUnrecognised = re.compile("Unrecognised track:", re.MULTILINE)
        if re.search(reUnrecognised, self.saved_stderr.getvalue()):
            self.assertTrue(False, "Didn't process all track records: %s" % self.saved_stderr.getvalue())


    def runTestSQL(self, input):
        optionsSQL = MyOptions("testdb", "", sql=True)
        dbname = "%s.db" % optionsSQL.dbname
        if os.path.exists(dbname):
            os.remove(dbname)
        saved_stdoutput = StringIO()
        saved_stderr = StringIO()
        log2sql = Log2sql(optionsSQL, instream=StringIO(input), outstream=saved_stdoutput, errstream=saved_stderr)
        log2sql.processLog()
        return sqlite3.connect(dbname)

    def testClientLockRecords(self):
        "Extra record for client lock"

        # Test parsing of sync with client lock info
        input = """
Perforce server info:
	2017/02/15 13:46:42 pid 81805 bruno@robert_cowham-dvcs-1487082773 10.62.185.98 [p4/2016.2/LINUX26X86_64/1468155] 'user-client -d -f bruno.139631598948304.irp210-h03'
Perforce server info:
	2017/02/15 13:46:42 pid 81805 bruno@robert_cowham-dvcs-1487082773 10.62.185.98 [p4/2016.2/LINUX26X86_64/1468155] 'user-client -d -f bruno.139631598948304.irp210-h03'
--- clients/bruno%2E139631598948304%2Eirp210-h03(W)
---   total lock wait+held read/write 0ms+0ms/0ms+9ms

Perforce server info:
	2017/02/15 13:46:42 pid 81805 completed .009s 8+1us 0+1408io 0+0net 4088k 0pf
Perforce server info:
	2017/02/15 13:46:42 pid 81805 bruno@robert_cowham-dvcs-1487082773 10.62.185.98 [p4/2016.2/LINUX26X86_64/1468155] 'user-client -d -f bruno.139631598948304.irp210-h03'
--- lapse .009s
--- usage 8+1us 0+1408io 0+0net 4088k 0pf
--- rpc msgs/size in+out 0+1/0mb+0mb himarks 318788/318788 snd/rcv .001s/.002s
--- db.user
---   pages in+out+cached 3+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
"""
        md5 = "5f1deb0b9ceec4f4906685722f6c8744"
        expected = """INSERT IGNORE INTO tableUse VALUES ("%s",2,"user",3,0,2,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"clients_W",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,0,0,9,0,0,0,9,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("%s",2,81805,"2017-02-15 13:46:42","2017-02-15 13:46:42",NULL,0.009,"bruno","robert_cowham-dvcs-1487082773","10.62.185.98","p4/2016.2/LINUX26X86_64/1468155","user-client","-d -f bruno.139631598948304.irp210-h03",0,1,0,0,318788,318788,.001,.002,8,1,0,1408,0,0,4088,0,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % (md5, md5, md5)

        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(row[0], md5)
        self.assertEqual(row[3], '2017-02-15 13:46:42')
        self.assertEqual(row[4], '2017-02-15 13:46:42')
        conn.close()

    def testBasicParsing(self):
        "simple parsing"

        # Test parsing of sync with 3 log entries
        input = """
Perforce server info:
	2015/09/02 15:23:09 pid 1616 robert@robert-test 127.0.0.1 [Microsoft Visual Studio 2013/12.0.21005.1] 'user-sync //...'
Perforce server info:
	2015/09/02 15:23:09 pid 1616 compute end .031s
Perforce server info:
	2015/09/02 15:23:09 pid 1616 completed .031s
"""
        md5 = "51ae6850c357585e594720f7efe9bfc0"
        if python3:
            md5 = "51ae6850c357585e594720f7efe9bfc0"
        expected = """INSERT IGNORE INTO process VALUES ("%s",2,1616,"2015-09-02 15:23:09","2015-09-02 15:23:09",0.031,0.031,"robert","robert-test","127.0.0.1","Microsoft Visual Studio 2013/12.0.21005.1","user-sync","//...",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5

        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(row[0], md5)
        self.assertEqual(row[3], '2015-09-02 15:23:09')
        conn.close()


        # Same as above with invalid Unicode strings
        input = """
Perforce server info:
	2015/09/02 15:23:09 pid 1616 robert@robert-test 127.0.0.1 [Microsoft® Visual Studio® 2013/12.0.21005.1] 'user-sync //...'
Perforce server info:
	2015/09/02 15:23:09 pid 1616 compute end .031s
Perforce server info:
	2015/09/02 15:23:09 pid 1616 completed .031s
"""
        md5 = "4f808949ed1932ddfeff8db1ce9c6b14"
        expected = """INSERT IGNORE INTO process VALUES ("%s",2,1616,"2015-09-02 15:23:09","2015-09-02 15:23:09",0.031,0.031,"robert","robert-test","127.0.0.1","Microsoft® Visual Studio® 2013/12.0.21005.1","user-sync","//...",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5
        if python3:
            md5 = "925f8e5b6ccff960001f246225feb562"
            expected = """INSERT IGNORE INTO process VALUES ("%s",2,1616,"2015-09-02 15:23:09","2015-09-02 15:23:09",0.031,0.031,"robert","robert-test","127.0.0.1","Microsoft® Visual Studio® 2013/12.0.21005.1","user-sync","//...",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5

        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(row[0], md5)
        self.assertEqual(row[3], '2015-09-02 15:23:09')
        conn.close()

    def testThreeRecords(self):
        "Extra record for client lock"

        # Test parsing of sync with 3 log entries

        input = """
Perforce server info:
	2015/09/02 15:23:11 pid 1616 robert@robert-test 127.0.0.1 [Microsoft Visual Studio 2013/12.0.21005.1] 'user-changes -c robert-test -m 1 -s pending -u robert'
Perforce server info:
	2015/09/02 15:23:11 pid 1616 compute end .047s
Perforce server info:
	2015/09/02 15:23:11 pid 1616 completed .047s
"""
        md5 = "df655d67bf61ab0e6e53d67bb0fe3674"
        if python3:
            md5 = "df655d67bf61ab0e6e53d67bb0fe3674"
        expected = """INSERT IGNORE INTO process VALUES ("%s",2,1616,"2015-09-02 15:23:11","2015-09-02 15:23:11",0.047,0.047,"robert","robert-test","127.0.0.1","Microsoft Visual Studio 2013/12.0.21005.1","user-changes","-c robert-test -m 1 -s pending -u robert",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5

        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(row[0], md5)
        self.assertEqual(row[3], '2015-09-02 15:23:11')
        self.assertEqual(row[4], '2015-09-02 15:23:11')
        self.assertEqual(row[5], 0.047)
        conn.close()

    def testSwarm(self):
        "Swarm style entry"

        # Test parsing of swarm style entry
        input = r"""
Perforce server info:
	2016/12/21 08:39:39 pid 14769 perforce@~tmp.1482305462.13038.585a2fb6041cc1.60954329 192.168.18.31 [SWARM/2016.2/1446446] 'user-counter -u swarm-activity-fffec3dd {"type":"change","link":["change",{"change":1005814}],"user":"sahaltran05","action":"committed","target":"change 1005814","preposition":"into","description":"Mac address filtering and fixing the naming collision for the SSH and telnet libraries\n","details":null,"topic":"changes\/1005814","depotFile":null,"time":1482305978,"behalfOf":null,"projects":{"sah-automation":["sah-tests"]},"streams":["user-sahaltran05","personal-sahaltran05","project-sah-automation","group-p4altran","group-sah_app","group-sah_commun_modules","group-sah_components","group-sah_demo","group-sah_hardco","group-sah_nanterre","group-sah_nanterre_opensource","group-sah_opensource","group-sah_stbconfig","group-sah_stbconfig_dev","group-sah_system","group-sah_third_party","group-sah_validation","group-sah_wijgmaal","personal-sah4011"],"change":1005814}'
Perforce server info:
	2016/12/21 08:39:39 pid 14769 completed .003s 4+0us 0+16io 0+0net 6432k 0pf
"""
        md5 = "fc41244739bdc71e81bcabbfc93124da"
        if python3:
            md5 = "fc41244739bdc71e81bcabbfc93124da"
        expected = """INSERT IGNORE INTO process VALUES ("%s",2,14769,"2016-12-21 08:39:39","2016-12-21 08:39:39",NULL,0.003,"perforce","~tmp.1482305462.13038.585a2fb6041cc1.60954329","192.168.18.31","SWARM/2016.2/1446446","user-counter","-u swarm-activity-fffec3dd",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5

        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(row[0], md5)
        self.assertEqual(row[3], '2016-12-21 08:39:39')
        self.assertEqual(row[4], '2016-12-21 08:39:39')
        conn.close()

    def testGitFusion(self):
        "GitFusion style entry"

        # Test parsing of git-fusion style entry
        input = r"""
Perforce server info:
	2016/10/19 12:01:08 pid 10664 git-fusion-user@GF-TRIGGER-567d67de-962 10.100.104.199 [p4/2016.1/NTX64/1396108] 'user-key git-fusion-reviews-common-lock-owner {"server_id": "p4gf_submit_trigger", "process_id": 5068, "start_time": "2016-10-19 12:01:08"}'
--- lapse .875s
--- rpc msgs/size in+out 2+3/0mb+0mb himarks 523588/523588 snd/rcv .000s/.015s
--- db.nameval
---   pages in+out+cached 6+4+4
---   locks read/write 0/1 rows get+pos+scan put+del 0+0+0 1+0
---   total lock wait+held read/write 0ms+0ms/16ms+15ms
--- db.user
---   pages in+out+cached 4+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
---   total lock wait+held read/write 0ms+16ms/0ms+0ms
--- db.group
---   pages in+out+cached 7+0+6
---   locks read/write 1/0 rows get+pos+scan put+del 0+3+67 0+0
---   total lock wait+held read/write 0ms+15ms/0ms+0ms
--- db.trigger
---   pages in+out+cached 21+0+20
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+486 0+0
---   total lock wait+held read/write 0ms+47ms/0ms+0ms
--- db.protect
---   pages in+out+cached 282+0+96
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+14495 0+0
---   total lock wait+held read/write 0ms+641ms/0ms+0ms
Perforce server info:
	2016/10/19 12:01:09 pid 10664 completed .844s
"""
        md5 = "afafbfd330e2378418bfb4025a86617c"
        expected = """INSERT IGNORE INTO tableUse VALUES ("%s",2,"nameval",6,4,4,0,1,0,0,0,1,0,0,0,16,15,0,0,16,15,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"protect",282,0,96,1,0,0,1,14495,0,0,0,641,0,0,0,641,0,0,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"trigger",21,0,20,1,0,0,1,486,0,0,0,47,0,0,0,47,0,0,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"group",7,0,6,1,0,0,3,67,0,0,0,15,0,0,0,15,0,0,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"user",4,0,3,1,0,1,0,0,0,0,0,16,0,0,0,16,0,0,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("%s",2,10664,"2016-10-19 12:01:08","2016-10-19 12:01:09",NULL,0.844,"git-fusion-user","GF-TRIGGER-567d67de-962","10.100.104.199","p4/2016.1/NTX64/1396108","user-key","git-fusion-reviews-common-lock-owner",2,3,0,0,523588,523588,.000,.015,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % (md5, md5, md5, md5, md5, md5)

        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(md5, row[0])
        self.assertEqual('2016-10-19 12:01:08', row[3])
        self.assertEqual('2016-10-19 12:01:09', row[4])
        self.assertEqual(0.844, row[6])
        conn.close()
        
    def testLongCommand(self):
        "Long commands"

        input = r"""
Perforce server info:
	2015/09/02 16:43:36 pid 4500 robert@robert-test 127.0.0.1 [Microsoft Visual Studio 2013/12.0.21005.1] 'user-reconcile -eadf -c 12253 c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt'
Perforce server info:
	2015/09/02 16:43:36 pid 4500 completed .187s
Perforce server info:
	2015/09/02 16:43:36 pid 4500 robert@robert-test 127.0.0.1 [Microsoft Visual Studio 2013/12.0.21005.1] 'user-reconcile -eadf -c 12253 c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt c:\temp\robert-test\test\VEER!-%-#-@-$-&-(-)\fred - Copy.txt'
--- clients/robert-test(W)
---   total lock wait+held read/write 0ms+0ms/0ms+172ms
"""
        md5 = "fbf9c435752ee86fd40040d8aa0d4daf"
        if python3:
            md5 = "fbf9c435752ee86fd40040d8aa0d4daf"
        expected = """INSERT IGNORE INTO process VALUES ("%s",2,4500,"2015-09-02 16:43:36","2015-09-02 16:43:36",NULL,0.187,"robert","robert-test","127.0.0.1","Microsoft Visual Studio 2013/12.0.21005.1","user-reconcile",
COMMIT;
BEGIN TRANSACTION;
""" % (md5)

        self.runTestText(expected, input, longlines=True)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        self.assertEqual(row[0], md5)
        self.assertEqual(row[3], '2015-09-02 16:43:36')
        self.assertEqual(row[4], '2015-09-02 16:43:36')
        conn.close()

    def testIgnoreErrors(self):
        "Long commands"

        input = r"""
Perforce server info:
	2017/02/09 17:22:35 pid 6582 perforce@irp210-h01 127.0.0.1 [unnamed p4-python script/v81] 'user-client -i'
Perforce server info:
	2017/02/09 17:22:35 pid 6582 perforce@perforce.140313515062736 127.0.0.1 [unnamed p4-python script/v81] 'user-sync //perforce.140313515062736/...'
Perforce server error:
	Date 2017/02/09 17:22:35:
	Pid 6582
	Operation: user-sync
	Librarian checkout depot/main/01/01/most/sites/have/longer/paths/jam/src/Build.com failed.
	open for read: depot/main/01/01/most/sites/have/longer/paths/jam/src/Build.com,v: No such file or directory
"""
        md5 = "eb54f394187e7e4e6ce6fd2eeb971081"
        expected = """INSERT IGNORE INTO process VALUES ("eb54f394187e7e4e6ce6fd2eeb971081",2,6582,"2017-02-09 17:22:35",NULL,NULL,NULL,"perforce","irp210-h01","127.0.0.1","unnamed p4-python script/v81","user-client","-i",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
INSERT IGNORE INTO process VALUES ("45de325534d03cd4d7cda68fd9b7b24d",4,6582,"2017-02-09 17:22:35",NULL,NULL,NULL,"perforce","perforce.140313515062736","127.0.0.1","unnamed p4-python script/v81","user-sync","//perforce.140313515062736/...",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
COMMIT;
BEGIN TRANSACTION;
"""
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(2, len(rows))
        row = rows[0]
        self.assertEqual(md5, row[0])
        self.assertEqual('2017-02-09 17:22:35', row[3])
        self.assertEqual(None, row[4])
        conn.close()


    def testNetworkEstimates(self):
        "Several lines of text"

        input = """
Perforce server info:
	2017/02/15 10:11:30 pid 4917 bruno@bruno.140451462678608 10.62.185.99 [unnamed p4-python script/v81] 'user-have'
Perforce server info:
	2017/02/15 10:11:30 pid 4917 completed .002s 2+0us 0+0io 0+0net 8932k 0pf
Perforce server info:
	2017/02/15 10:11:30 pid 4917 bruno@bruno.140451462678608 10.62.185.99 [unnamed p4-python script/v81] 'user-sync //bruno.140451462678608/...'
Perforce server info:
	2017/02/15 10:11:30 pid 4917 compute end .020s 16+3us 0+0io 0+0net 8964k 0pf
Perforce server info:
	Server network estimates: files added/updated/deleted=1/3/0, bytes added/updated=111325/813906
Perforce server info:
	2017/02/15 10:11:30 pid 4917 completed .034s 19+4us 0+8io 0+0net 8996k 0pf
"""
        expected = """INSERT IGNORE INTO process VALUES ("b190b0d24f053ee802a6e1c1eeabb26d",2,4917,"2017-02-15 10:11:30","2017-02-15 10:11:30",NULL,0.002,"bruno","bruno.140451462678608","10.62.185.99","unnamed p4-python script/v81","user-have","NULL",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
INSERT IGNORE INTO process VALUES ("3a45c4cc53cef5d2764b2dcdb0b83053",6,4917,"2017-02-15 10:11:30","2017-02-15 10:11:30",0.02,0.034,"bruno","bruno.140451462678608","10.62.185.99","unnamed p4-python script/v81","user-sync","//bruno.140451462678608/...",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
COMMIT;
BEGIN TRANSACTION;
"""
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(2, len(rows))
        row = rows[0]
        self.assertEqual('2017-02-15 10:11:30', row[3])
        self.assertEqual('2017-02-15 10:11:30', row[4])
        row = rows[1]
        self.assertEqual(0.02, row[5])
        self.assertEqual(0.034, row[6])
        conn.close()

    def testFullTrack(self):
        "Full track output with duplicate pids"

        input = """
Perforce server info:
	2017/02/15 13:48:40 pid 82509 bruno@bruno.140147714537552 10.62.185.101 [unnamed p4-python script/v81] 'user-delete /mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/nasdf'
Perforce server info:
	2017/02/15 13:48:40 pid 82509 completed .004s 0+0us 0+16io 0+0net 16640k 0pf
Perforce server info:
	2017/02/15 13:48:40 pid 82509 bruno@bruno.140147714537552 10.62.185.101 [unnamed p4-python script/v81] 'user-delete /mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/nasdf'
--- lapse .004s
--- rpc msgs/size in+out 2+4/0mb+0mb himarks 318788/318788 snd/rcv .000s/.004s
--- db.counters
---   pages in+out+cached 2+0+2
---   locks read/write 0/1 rows get+pos+scan put+del 1+0+0 0+0

Perforce server info:
	2017/02/15 13:48:40 pid 82509 bruno@bruno.140147714537552 10.62.185.101 [unnamed p4-python script/v81] 'user-edit /mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/TtEVHkGZFv2nCHgbAmp'
Perforce server info:
	2017/02/15 13:48:40 pid 82509 completed .004s 0+0us 0+16io 0+0net 16640k 0pf
Perforce server info:
	2017/02/15 13:48:40 pid 82509 bruno@bruno.140147714537552 10.62.185.101 [unnamed p4-python script/v81] 'user-edit /mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/TtEVHkGZFv2nCHgbAmp'
--- lapse .004s
--- rpc msgs/size in+out 2+4/0mb+0mb himarks 318788/318788 snd/rcv .000s/.004s
--- db.counters
---   pages in+out+cached 2+0+2
---   locks read/write 0/1 rows get+pos+scan put+del 1+0+0 0+0
--- db.logger
---   pages in+out+cached 2+0+1
---   locks read/write 0/1 rows get+pos+scan put+del 0+0+0 0+0
--- db.user
---   pages in+out+cached 1+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
--- db.group
---   pages in+out+cached 1+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 0+2+3 0+0
--- db.domain
---   pages in+out+cached 1+0+4
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
--- db.view
---   pages in+out+cached 2+0+4
---   locks read/write 2/0 rows get+pos+scan put+del 0+2+4 0+0
--- db.have
---   pages in+out+cached 1+0+38
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+2 0+0
--- db.rev
---   pages in+out+cached 3+0+29
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+1 0+0
--- db.locks
---   pages in+out+cached 4+3+8
---   locks read/write 1/1 rows get+pos+scan put+del 0+1+1 1+0
--- db.working
---   pages in+out+cached 3+3+4
---   locks read/write 1/1 rows get+pos+scan put+del 1+1+1 1+0
--- db.protect
---   pages in+out+cached 1+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+20 0+0
--- clients/bruno%2E140147714537552%2Eirp210-h04(W)
---   total lock wait+held read/write 0ms+0ms/0ms+4ms

Perforce server info:
	2017/02/15 13:48:41 pid 82509 bruno@bruno.140147714537552 10.62.185.101 [unnamed p4-python script/v81] 'user-edit /mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/asdf'
Perforce server info:
	2017/02/15 13:48:41 pid 82509 completed .008s 0+0us 0+16io 0+0net 16640k 0pf
"""
        expected = """INSERT IGNORE INTO tableUse VALUES ("5bba38da4d58b445353431a7b447e2b5",2,"counters",2,0,2,0,1,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("5bba38da4d58b445353431a7b447e2b5",2,82509,"2017-02-15 13:48:40","2017-02-15 13:48:40",NULL,0.004,"bruno","bruno.140147714537552","10.62.185.101","unnamed p4-python script/v81","user-delete","/mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/nasdf",2,4,0,0,318788,318788,.000,.004,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"clients_W",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,0,0,4,0,0,0,4,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"domain",1,0,4,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"group",1,0,2,1,0,0,2,3,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"working",3,3,4,1,1,1,1,1,1,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"rev",3,0,29,1,0,0,1,1,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"protect",1,0,2,1,0,0,1,20,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"locks",4,3,8,1,1,0,1,1,1,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"user",1,0,2,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"have",1,0,38,1,0,0,1,2,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"logger",2,0,1,0,1,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"counters",2,0,2,0,1,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,"view",2,0,4,2,0,0,2,4,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("3c8d7a2eab4ffbd39a56dc92fc0192bd.14",14,82509,"2017-02-15 13:48:40","2017-02-15 13:48:40",NULL,0.004,"bruno","bruno.140147714537552","10.62.185.101","unnamed p4-python script/v81","user-edit","/mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/TtEVHkGZFv2nCHgbAmp",2,4,0,0,318788,318788,.000,.004,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
INSERT IGNORE INTO process VALUES ("fbc3acfe25823b480df7d730c69d22f4",58,82509,"2017-02-15 13:48:41","2017-02-15 13:48:41",NULL,0.008,"bruno","bruno.140147714537552","10.62.185.101","unnamed p4-python script/v81","user-edit","/mnt/ebc-201/bench_tests/bruno.140147714537552/Jam/REL2.1/src/asdf",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
"""
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(3, len(rows))
        conn.close()


    def testFileFetches(self):
        "These get duplicate pids in same second"

        input = """

Perforce server info:
	2017/03/06 11:53:50 pid 113249 serviceUser@unknown 10.62.185.99 [p4d/2016.2/LINUX26X86_64/1468155] 'rmt-FileFetch'
--- rpc msgs/size in+out 0+2/0mb+0mb himarks 318788/318788 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 2+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0

Perforce server info:
	2017/03/06 11:53:50 pid 113249 serviceUser@unknown 10.62.185.99 [p4d/2016.2/LINUX26X86_64/1468155] 'rmt-FileFetch'
--- rpc msgs/size in+out 0+2/0mb+0mb himarks 318788/318788 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0

Perforce server info:
	2017/03/06 11:53:50 pid 113249 serviceUser@unknown 10.62.185.99 [p4d/2016.2/LINUX26X86_64/1468155] 'rmt-FileFetch'
--- rpc msgs/size in+out 0+2/0mb+0mb himarks 318788/318788 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+2
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0

"""
        expected = """INSERT IGNORE INTO tableUse VALUES ("1068df74feaa6087ef04a30c5ed0c149",3,"user",2,0,2,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("1068df74feaa6087ef04a30c5ed0c149",3,113249,"2017-03-06 11:53:50","2017-03-06 11:53:50",NULL,NULL,"serviceUser","unknown","10.62.185.99","p4d/2016.2/LINUX26X86_64/1468155","rmt-FileFetch","NULL",0,2,0,0,318788,318788,.000,.000,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
INSERT IGNORE INTO tableUse VALUES ("1068df74feaa6087ef04a30c5ed0c149",10,"user",1,0,2,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("1068df74feaa6087ef04a30c5ed0c149",10,113249,"2017-03-06 11:53:50","2017-03-06 11:53:50",NULL,NULL,"serviceUser","unknown","10.62.185.99","p4d/2016.2/LINUX26X86_64/1468155","rmt-FileFetch","NULL",0,2,0,0,318788,318788,.000,.000,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
INSERT IGNORE INTO tableUse VALUES ("1068df74feaa6087ef04a30c5ed0c149",17,"user",1,0,2,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("1068df74feaa6087ef04a30c5ed0c149",17,113249,"2017-03-06 11:53:50","2017-03-06 11:53:50",NULL,NULL,"serviceUser","unknown","10.62.185.99","p4d/2016.2/LINUX26X86_64/1468155","rmt-FileFetch","NULL",0,2,0,0,318788,318788,.000,.000,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
COMMIT;
BEGIN TRANSACTION;
"""
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(3, len(rows))
        conn.close()


    def testChanges(self):
        "These get duplicate pids for change -o"

        input = """
Perforce server info:
	2016/10/19 14:53:48 pid 4496 lcheng@lcheng 10.100.72.195 [P4V/NTX64/2014.1/888424/v76] 'user-change -o'

Perforce server info:
	2016/10/19 14:53:48 pid 4496 completed .015s
Perforce server info:
	2016/10/19 14:53:48 pid 4496 lcheng@lcheng 10.100.72.195 [P4V/NTX64/2014.1/888424/v76] 'user-change -o'
--- lapse .015s
--- rpc msgs/size in+out 0+1/0mb+0mb himarks 523588/64836 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
--- db.group
---   pages in+out+cached 1+0+7
---   locks read/write 1/0 rows get+pos+scan put+del 0+6+11 0+0

Perforce server info:
	2016/10/19 14:53:48 pid 4496 lcheng@lcheng 10.100.72.195 [P4V/NTX64/2014.1/888424/v76] 'user-change -o'

Perforce server info:
	2016/10/19 14:53:48 pid 4496 completed .016s
Perforce server info:
	2016/10/19 14:53:48 pid 4496 lcheng@lcheng 10.100.72.195 [P4V/NTX64/2014.1/888424/v76] 'user-change -o'
--- lapse .016s
--- rpc msgs/size in+out 0+1/0mb+0mb himarks 523588/64836 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
--- db.group
---   pages in+out+cached 1+0+7
---   locks read/write 1/0 rows get+pos+scan put+del 0+6+11 0+0
"""
        expected = """INSERT IGNORE INTO tableUse VALUES ("3bfd7dbadcf671543f98f9be1430aaa3",2,"group",1,0,7,1,0,0,6,11,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3bfd7dbadcf671543f98f9be1430aaa3",2,"user",1,0,3,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3bfd7dbadcf671543f98f9be1430aaa3.18",18,"group",1,0,7,1,0,0,6,11,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("3bfd7dbadcf671543f98f9be1430aaa3.18",18,"user",1,0,3,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("3bfd7dbadcf671543f98f9be1430aaa3",2,4496,"2016-10-19 14:53:48","2016-10-19 14:53:48",NULL,0.015,"lcheng","lcheng","10.100.72.195","P4V/NTX64/2014.1/888424/v76","user-change","-o",0,1,0,0,523588,64836,.000,.000,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
INSERT IGNORE INTO process VALUES ("3bfd7dbadcf671543f98f9be1430aaa3.18",18,4496,"2016-10-19 14:53:48","2016-10-19 14:53:48",NULL,0.016,"lcheng","lcheng","10.100.72.195","P4V/NTX64/2014.1/888424/v76","user-change","-o",0,1,0,0,523588,64836,.000,.000,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
"""
        self.runTestText(expected, input)

        # Test with SQL
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(2, len(rows))
        conn.close()

    def testDuplicateCmds(self):
        "These pids re-used on same connection for same command within same second - so appear to be duplicates"

        input = """
Perforce server info:
	2017/12/07 15:00:27 pid 148889 fred.smith@FRED-WS 10.10.16.172/10.10.65.237 [P4VS/2017.2.159.0319] 'user-fstat -Olhp x:/dev/Client/IService.cs'

Perforce server info:
	2017/12/07 15:00:27 pid 148889 completed .001s 1+0us 0+0io 0+0net 3924k 0pf
Perforce server info:
	2017/12/07 15:00:27 pid 148889 fred.smith@FRED-WS 10.10.16.172/10.10.65.237 [P4VS/2017.2.159.0319] 'user-fstat -Olhp x:/dev/Client/IService.cs'
--- lapse .002s
--- usage 2+0us 0+8io 0+0net 3924k 0pf
--- rpc msgs/size in+out 0+1/0mb+0mb himarks 318788/523588 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0

Perforce server info:
	2017/12/07 15:00:27 pid 148889 fred.smith@FRED-WS 10.10.16.172/10.10.65.237 [P4VS/2017.2.159.0319] 'user-fstat -Olhp x:/dev/Client/IService.cs'
Perforce server info:
	2017/12/07 15:00:27 pid 148889 completed .001s 1+0us 0+0io 0+0net 3924k 0pf
Perforce server info:
	2017/12/07 15:00:27 pid 148889 fred.smith@FRED-WS 10.10.16.172/10.10.65.237 [P4VS/2017.2.159.0319] 'user-fstat -Olhp x:/dev/Client/IService.cs'
--- lapse .002s
--- usage 2+0us 0+8io 0+0net 3924k 0pf
--- rpc msgs/size in+out 0+1/0mb+0mb himarks 318788/523588 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0

Perforce server info:
	2017/12/07 15:00:27 pid 148889 fred.smith@FRED-WS 10.10.16.172/10.10.65.237 [P4VS/2017.2.159.0319] 'user-fstat -Olhp x:/dev/Client/IService.cs'

Perforce server info:
	2017/12/07 15:00:27 pid 148889 completed .001s 1+0us 0+0io 0+0net 3924k 0pf
Perforce server info:
	2017/12/07 15:00:27 pid 148889 fred.smith@FRED-WS 10.10.16.172/10.10.65.237 [P4VS/2017.2.159.0319] 'user-fstat -Olhp x:/dev/Client/IService.cs'
--- lapse .002s
--- usage 2+0us 0+8io 0+0net 3924k 0pf
--- rpc msgs/size in+out 0+1/0mb+0mb himarks 318788/523588 snd/rcv .000s/.000s
--- db.user
---   pages in+out+cached 1+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0

"""
        expected = """INSERT IGNORE INTO tableUse VALUES ("199194a5914bd194cc9a3c54115b549b",2,"user",1,0,3,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("199194a5914bd194cc9a3c54115b549b.16",16,"user",1,0,3,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("199194a5914bd194cc9a3c54115b549b.29",29,"user",1,0,3,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO process VALUES ("199194a5914bd194cc9a3c54115b549b",2,148889,"2017-12-07 15:00:27","2017-12-07 15:00:27",NULL,0.001,"fred.smith","FRED-WS","10.10.16.172/10.10.65.237","P4VS/2017.2.159.0319","user-fstat","-Olhp x:/dev/Client/IService.cs",0,1,0,0,318788,523588,.000,.000,2,0,0,8,0,0,3924,0,0,NULL);
INSERT IGNORE INTO process VALUES ("199194a5914bd194cc9a3c54115b549b.16",16,148889,"2017-12-07 15:00:27","2017-12-07 15:00:27",NULL,0.001,"fred.smith","FRED-WS","10.10.16.172/10.10.65.237","P4VS/2017.2.159.0319","user-fstat","-Olhp x:/dev/Client/IService.cs",0,1,0,0,318788,523588,.000,.000,2,0,0,8,0,0,3924,0,0,NULL);
INSERT IGNORE INTO process VALUES ("199194a5914bd194cc9a3c54115b549b.29",29,148889,"2017-12-07 15:00:27","2017-12-07 15:00:27",NULL,0.001,"fred.smith","FRED-WS","10.10.16.172/10.10.65.237","P4VS/2017.2.159.0319","user-fstat","-Olhp x:/dev/Client/IService.cs",0,1,0,0,318788,523588,.000,.000,2,0,0,8,0,0,3924,0,0,NULL);
COMMIT;
BEGIN TRANSACTION;
"""
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(3, len(rows))
        c.execute('SELECT * from tableUse;')
        rows = c.fetchall()
        self.assertEqual(3, len(rows))
        conn.close()

    def testNonUtf8(self):
        "unicode errors - particularly in python3"

        # Same as above with invalid Unicode strings
        input = """
Perforce server info:
	2017/12/07 15:26:59 pid 86264 john.smith@TEST_WS 10.10.16.172/10.10.48.217 [P4V/NTX64/2017.3/1592764/v83] 'user-fstat -Olhp x:\ws\data\interior.xml x:\ws\data\y2017\� x:\ws\data\y2017\content_audio.xml'
Perforce server info:
	2017/12/07 15:26:59 pid 86264 completed .004s 3+1us 0+0io 0+0net 6996k 0pf
"""
        md5 = "ba5e13f41770e367b76698440103f793"
        expected = r"""INSERT IGNORE INTO process VALUES ("%s",2,86264,"2017-12-07 15:26:59","2017-12-07 15:26:59",NULL,0.004,"john.smith","TEST_WS","10.10.16.172/10.10.48.217","P4V/NTX64/2017.3/1592764/v83","user-fstat","-Olhp x:\\ws\\data\\interior.xml x:\\ws\\data\\y2017\\� x:\\ws\\data\\y2017\\content_audio.xml",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5
        if python3:
            md5 = "4bf0fade6cb904abbaf7ccb8eba630a9"
            expected = r"""INSERT IGNORE INTO process VALUES ("%s",2,86264,"2017-12-07 15:26:59","2017-12-07 15:26:59",NULL,0.004,"john.smith","TEST_WS","10.10.16.172/10.10.48.217","P4V/NTX64/2017.3/1592764/v83","user-fstat","-Olhp x:\\ws\\data\\interior.xml x:\\ws\\data\\y2017\\� x:\\ws\\data\\y2017\\content_audio.xml",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % md5
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        if python3:
            self.assertEqual(row[0], md5)
        else:
            self.assertEqual(row[0], u'ba5e13f41770e367b76698440103f793')
        self.assertEqual(row[3], u'2017-12-07 15:26:59')
        conn.close()

    def testPeeks(self):
        "Process peek count records"

        # Same as above with invalid Unicode strings
        input = r"""
Perforce server info:
	2017/12/07 15:00:01 pid 145999 john.smith@john.smith_LON 10.10.16.171/10.10.48.88 [P4VS/2017.2.159.0319] 'user-fstat -Olhp -m 100000 x:/ws/*'

Perforce server info:
	2017/12/07 15:00:01 pid 145999 completed .007s 0+3us 0+8io 0+0net 3920k 0pf
Perforce server info:
	2017/12/07 15:00:01 pid 145999 john.smith@john.smith_LON 10.10.16.171/10.10.48.88 [P4VS/2017.2.159.0319] 'user-fstat -Olhp -m 100000 x:/ws/*'
--- lapse .007s
--- usage 1+3us 0+24io 0+0net 3920k 0pf
--- rpc msgs/size in+out 2+3/0mb+0mb himarks 318788/2096452 snd/rcv .000s/.002s
--- db.user
---   pages in+out+cached 4+0+3
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
--- db.group
---   pages in+out+cached 16+0+15
---   locks read/write 1/0 rows get+pos+scan put+del 0+18+35 0+0
--- db.domain
---   pages in+out+cached 5+0+4
---   locks read/write 1/0 rows get+pos+scan put+del 1+0+0 0+0
--- db.view
---   pages in+out+cached 3+0+6
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+13 0+0
--- db.have
---   pages in+out+cached 8+0+7
---   locks read/write 0/0 rows get+pos+scan put+del 0+1+1 0+0
---   peek count 1 wait+held total/max 2ms+3ms/4ms+5ms
--- db.revdx
---   pages in+out+cached 7+0+6
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+1 0+0
--- db.revhx
---   pages in+out+cached 8+0+7
---   locks read/write 1/0 rows get+pos+scan put+del 0+1+1 0+0
--- db.rev
---   pages in+out+cached 1+0+1
---   locks read/write 1/0 rows get+pos+scan put+del 0+0+0 0+0
--- db.revtx
---   pages in+out+cached 1+0+1
---   locks read/write 1/0 rows get+pos+scan put+del 0+0+0 0+0
--- db.locks
---   pages in+out+cached 1+0+1
---   locks read/write 0/0 rows get+pos+scan put+del 0+0+0 0+0
---   peek count 1 wait+held total/max 2ms+3ms/4ms+5ms

"""
        md5 = "451985326097e04e029a0456529d8d2b"
        if python3:
            md5 = "451985326097e04e029a0456529d8d2b"
        expected = """INSERT IGNORE INTO process VALUES ("%s",2,145999,"2017-12-07 15:00:01","2017-12-07 15:00:01",NULL,0.007,"john.smith","john.smith_LON","10.10.16.171/10.10.48.88","P4VS/2017.2.159.0319","user-fstat","-Olhp -m 100000 x:/ws/*",2,3,0,0,318788,2096452,.000,.002,1,3,0,24,0,0,3920,0,0,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"domain",5,0,4,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"group",16,0,15,1,0,0,18,35,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"have",8,0,7,0,0,0,1,1,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,2,3,4,5);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"locks",1,0,1,0,0,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,2,3,4,5);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"rev",1,0,1,1,0,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"revdx",7,0,6,1,0,0,1,1,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"revhx",8,0,7,1,0,0,1,1,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"revtx",1,0,1,1,0,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"user",4,0,3,1,0,1,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",2,"view",3,0,6,1,0,0,1,13,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % (md5, md5, md5, md5, md5, md5, md5, md5, md5, md5, md5)
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        if python3:
            self.assertEqual(row[0], md5)
        else:
            self.assertEqual(row[0], md5)
        self.assertEqual(row[3], u'2017-12-07 15:00:01')
        conn.close()


    def testMetaDb(self):
        "Process multiple meta/db entries"

        input = r"""
Perforce server info:
        2017/12/07 15:00:01 pid 145941 builder@LON 10.10.16.171/10.10.20.195 [AutoWorker/1.0.0.0] 'user-sync //assets/level/instances.xml'

Perforce server info:
	2017/12/07 15:00:01 pid 145941 builder@LON 10.10.16.171/10.10.20.195 [AutoWorker/1.0.0.0] 'user-sync //assets/level/instances.xml'
--- meta/db(R)
---   total lock wait+held read/write 0ms+0ms/0ms+0ms

Perforce server info:
	2017/12/07 15:00:01 pid 145941 compute end .007s 3+1us 16+112io 0+0net 4452k 0pf 
Perforce server info:
	Server network estimates: files added/updated/deleted=0/0/0, bytes added/updated=0/0
Perforce server info:
	2017/12/07 15:00:01 pid 145941 builder@LON 10.10.16.171/10.10.20.195 [AutoWorker/1.0.0.0] 'user-sync //assets/level/instances.xml'
--- meta/db(R)
---   total lock wait+held read/write 0ms+0ms/0ms+0ms

Perforce server info:
	2017/12/07 15:00:01 pid 145941 compute end .007s 3+1us 16+128io 0+0net 4452k 0pf 
Perforce server info:
	Server network estimates: files added/updated/deleted=0/0/0, bytes added/updated=0/0
Perforce server info:
	2017/12/07 15:00:01 pid 145941 builder@LON 10.10.16.171/10.10.20.195 [AutoWorker/1.0.0.0] 'user-sync //assets/level/instances.xml'
--- meta/db(R)
---   total lock wait+held read/write 0ms+0ms/0ms+0ms

Perforce server info:
	2017/12/07 15:00:01 pid 145941 compute end .008s 4+1us 16+144io 0+0net 4452k 0pf 
Perforce server info:
	Server network estimates: files added/updated/deleted=0/0/0, bytes added/updated=0/0
Perforce server info:
	2017/12/07 15:00:01 pid 145941 builder@LON 10.10.16.171/10.10.20.195 [AutoWorker/1.0.0.0] 'user-sync //assets/level/instances.xml'
--- meta/db(R)
---   total lock wait+held read/write 0ms+0ms/0ms+0ms

Perforce server info:
	2017/12/07 15:00:01 pid 145941 compute end .008s 4+1us 16+160io 0+0net 4452k 0pf 
Perforce server info:
	Server network estimates: files added/updated/deleted=0/0/0, bytes added/updated=0/0
Perforce server info:
--- meta/db(R)
---   total lock wait+held read/write 0ms+0ms/0ms+0ms

Perforce server info:
	2017/12/07 15:00:01 pid 145941 compute end .110s 77+25us 112+3120io 0+0net 4964k 0pf
Perforce server info:
	Server network estimates: files added/updated/deleted=0/0/0, bytes added/updated=0/0
Perforce server info:
	2017/12/07 15:00:01 pid 145941 completed .111s 77+25us 112+3136io 0+0net 4964k 0pf

"""
        md5 = "d1c0c9f9173fb9e295de36cd4e0c5bfd"
        if python3:
            md5 = "d1c0c9f9173fb9e295de36cd4e0c5bfd"
        expected = """INSERT IGNORE INTO process VALUES ("%s",5,145941,"2017-12-07 15:00:01","2017-12-07 15:00:01",0.14,0.111,"builder","LON","10.10.16.171/10.10.20.195","AutoWorker/1.0.0.0","user-sync","//assets/level/instances.xml",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1,NULL);
INSERT IGNORE INTO tableUse VALUES ("%s",5,"meta_db_R",NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,0,0,0,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL);
COMMIT;
BEGIN TRANSACTION;
""" % (md5, md5)
        self.runTestText(expected, input)
        conn = self.runTestSQL(input)
        c = conn.cursor()
        c.execute('SELECT * from Process;')
        rows = c.fetchall()
        self.assertEqual(len(rows), 1)
        row = rows[0]
        if python3:
            self.assertEqual(row[0], md5)
        else:
            self.assertEqual(row[0], md5)
        self.assertEqual(row[3], u'2017-12-07 15:00:01')
        conn.close()

# Handle trigger intermediate output!
#
#         2017/12/07 15:00:21 pid 148469 Fred@LONWS 10.40.16.14/10.40.48.29 [3DSMax/1.0.0.0] 'user-change -i' trigger swarm.changesave
# lapse .044s
# Perforce server info:
#         2017/12/07 15:00:21 pid 148469 completed .413s 7+4us 0+584io 0+0net 4580k 0pf
# Perforce server info:
#         2017/12/07 15:00:21 pid 148469 Fred@LONWS 10.40.16.14/10.40.48.29 [3DSMax/1.0.0.0] 'user-change -i'
# --- lapse .413s
# --- usage 7+4us 0+592io 0+0net 4580k 0pf
# --- rpc msgs/size in+out 3+5/0mb+0mb himarks 318788/2096452 snd/rcv .000s/.052s
# --- db.counters
# ---   pages in+out+cached 6+3+2
# ---   locks read/write 0/2 rows get+pos+scan put+del 2+0+0 1+0

if __name__ == '__main__':
    unittest.main()