In case table is updated with different connection, read operations with do not return results for long time. I've run similar test with fdb in python on same database and got good latency as expected (<1s for same settings). Also same test in go gives decent latency on sqlite3 database, therefore all statements are correct. Please comment on this bug and possible workaraunds.
I've tested this with local database created with isql-fb with command CREATE DATABASE '/opt/firebird/database.fdb' USER 'SYSDBA' PASSWORD 'changeit';. Database contains a single table created with command create table numbers (i int not null primary key);
Here is code for measuring latency in go.
package main
import (
"database/sql"
"fmt"
"log"
"sync"
"time"
_ "github.com/nakagami/firebirdsql"
)
const (
host = "localhost"
database = "/opt/firebird/database.fdb"
user = "SYSDBA"
password = "changeit"
benchLenghtSeconds = 10.0
msgCount = 10
readInterval = 1
)
var (
writeDB *sql.DB
readDB *sql.DB
clearDB *sql.DB
writeTimes = make(map[int]time.Time)
readTimes = make(map[int]time.Time)
)
func read(wg *sync.WaitGroup) {
defer wg.Done()
lastRead := -1
for lastRead < msgCount-1 {
fmt.Println("read loop start")
rows, err := readDB.Query("SELECT i from numbers WHERE i>?", lastRead)
if err != nil {
log.Fatal(err)
}
fmt.Println("query done")
timestamp := time.Now()
for rows.Next() {
fmt.Println(`in "next" loop`)
var i int
if err := rows.Scan(&i); err != nil {
log.Fatal(err)
}
readTimes[i] = timestamp
fmt.Println("read ", i)
lastRead = i
}
fmt.Println(`after "next" loop`)
rows.Close()
time.Sleep(readInterval * time.Second)
}
}
func write(wg *sync.WaitGroup) {
defer wg.Done()
stmt, err := writeDB.Prepare("INSERT INTO numbers (i) VALUES (?);")
if err != nil {
log.Fatal(err)
}
defer stmt.Close()
for i := 0; i < msgCount; i++ {
_, err := stmt.Exec(i)
if err != nil {
log.Fatal(err)
}
writeTimes[i] = time.Now()
fmt.Println("wrote ", i)
time.Sleep(time.Duration(benchLenghtSeconds/msgCount) * time.Second)
}
}
func clearNumbers() {
if _, err := clearDB.Exec("DELETE FROM numbers;"); err != nil {
log.Fatal(err)
}
}
func main() {
var err error
writeDB, err = sql.Open("firebirdsql", fmt.Sprintf("%s:%s@%s/%s", user, password, host, database))
if err != nil {
log.Fatal(err)
}
defer writeDB.Close()
readDB, err = sql.Open("firebirdsql", fmt.Sprintf("%s:%s@%s/%s", user, password, host, database))
if err != nil {
log.Fatal(err)
}
defer writeDB.Close()
clearDB, err = sql.Open("firebirdsql", fmt.Sprintf("%s:%s@%s/%s", user, password, host, database))
if err != nil {
log.Fatal(err)
}
defer writeDB.Close()
clearNumbers()
wg := sync.WaitGroup{}
wg.Add(2)
go read(&wg)
go write(&wg)
wg.Wait()
mean := 0.0
for i, t := range writeTimes {
mean += readTimes[i].Sub(t).Seconds()
}
mean /= msgCount
fmt.Printf("mean latency: %v s\n", mean)
clearNumbers()
}
Output:
read loop start
wrote 0
query done
after "next" loop
wrote 1
read loop start
query done
after "next" loop
wrote 2
read loop start
query done
after "next" loop
wrote 3
read loop start
query done
after "next" loop
wrote 4
read loop start
query done
after "next" loop
wrote 5
read loop start
query done
after "next" loop
wrote 6
read loop start
query done
after "next" loop
wrote 7
read loop start
query done
after "next" loop
wrote 8
read loop start
query done
after "next" loop
wrote 9
read loop start
query done
after "next" loop
read loop start
query done
in "next" loop
read 0
in "next" loop
read 1
in "next" loop
read 2
in "next" loop
read 3
in "next" loop
read 4
in "next" loop
read 5
in "next" loop
read 6
in "next" loop
read 7
in "next" loop
read 8
in "next" loop
read 9
after "next" loop
mean latency: 5.5446701527 s
fdb test
import fdb
from timeit import default_timer
import asyncio
HOST = 'localhost'
DATABAASE = '/opt/firebird/database.fdb'
USER = 'SYSDBA'
PASSWORD='changeit'
BENCH_LENGTH_SECONDS = 10.0
MSG_COUNT=10
READ_INTERVAL = 1
con_write = fdb.connect(
host=HOST, database=DATABAASE,
user=USER, password=PASSWORD
)
con_read = fdb.connect(
host=HOST, database=DATABAASE,
user=USER, password=PASSWORD
)
con_cleanup = fdb.connect(
host=HOST, database=DATABAASE,
user=USER, password=PASSWORD
)
write_cur = con_write.cursor()
read_cur = con_read.cursor()
cleanup_cur = con_cleanup.cursor()
write_times = {}
read_times = {}
async def write():
for i in range(MSG_COUNT):
write_cur.execute("INSERT INTO numbers (i) VALUES (?);",(i,))
con_write.commit()
write_times[i]=default_timer()
await asyncio.sleep(BENCH_LENGTH_SECONDS/MSG_COUNT)
async def read():
last_read = -1
while last_read<MSG_COUNT-1:
res = read_cur.execute("SELECT i from numbers WHERE i>?;",(last_read,)).fetchall()
timestamp = default_timer()
for row in res:
read_times[row[0]]=timestamp
last_read = row[0]
await asyncio.sleep(READ_INTERVAL)
async def main():
f1 = loop.create_task(write())
f2 = loop.create_task(read())
await asyncio.wait([f1, f2])
# cleanup
cleanup_cur.execute('DELETE FROM numbers;')
con_cleanup.commit()
loop = asyncio.get_event_loop()
loop.run_until_complete(main())
loop.close()
# cleanup
cleanup_cur.execute('DELETE FROM numbers;')
con_cleanup.commit()
# count latency
diff = 0.0
for i,t in write_times.items():
diff+=read_times[i]-t
diff/=MSG_COUNT
print(f'mean latency: {diff*1000} ms')
output:
mean latency: 1.1342148995026946 ms
