From b99533a5ad1dfb70d26efbac48248df8ecc7eaff Mon Sep 17 00:00:00 2001 From: Damien Elmes Date: Fri, 18 Oct 2013 11:52:21 +0900 Subject: [PATCH] add logging to some scheduling and syncing code --- anki/cards.py | 12 ++++++++++++ anki/collection.py | 11 ++++++++++- anki/sched.py | 26 ++++++++++++++++++++++---- anki/sync.py | 9 +++++++++ aqt/main.py | 21 ++++++++++++++++++++- 5 files changed, 73 insertions(+), 6 deletions(-) diff --git a/anki/cards.py b/anki/cards.py index 7aa25978c..ee9f7b8c1 100644 --- a/anki/cards.py +++ b/anki/cards.py @@ -1,6 +1,7 @@ # -*- coding: utf-8 -*- # Copyright: Damien Elmes # License: GNU AGPL, version 3 or later; http://www.gnu.org/licenses/agpl.html +import pprint import time from anki.utils import intTime, timestampID, joinFields @@ -106,6 +107,7 @@ insert or replace into cards values self.odid, self.flags, self.data) + self.col.log(self) def flushSched(self): self.mod = intTime() @@ -121,6 +123,7 @@ lapses=?, left=?, odue=?, odid=?, did=? where id = ?""", self.mod, self.usn, self.type, self.queue, self.due, self.ivl, self.factor, self.reps, self.lapses, self.left, self.odue, self.odid, self.did, self.id) + self.col.log(self) def q(self, reload=False, browser=False): return self.css() + self._getQA(reload, browser)['q'] @@ -180,3 +183,12 @@ lapses=?, left=?, odue=?, odid=?, did=? where id = ?""", self.model(), joinFields(self.note().fields)) if self.ord not in ords: return True + + def __repr__(self): + d = dict(self.__dict__) + # remove non-useful elements + del d['_note'] + del d['_qa'] + del d['col'] + del d['timerStarted'] + return pprint.pformat(d, width=300) diff --git a/anki/collection.py b/anki/collection.py index dcb74c7b7..aaabcf160 100644 --- a/anki/collection.py +++ b/anki/collection.py @@ -51,6 +51,7 @@ class _Collection(object): def __init__(self, db, server=False): self.db = db self.path = db._path + self.log(self.path, anki.version) self.server = server self._lastSave = time.time() self.clearUndo() @@ -205,7 +206,9 @@ crt=?, mod=?, scm=?, dty=?, usn=?, ls=?, conf=?""", ########################################################################## def getCard(self, id): - return anki.cards.Card(self, id) + c = anki.cards.Card(self, id) + self.log(c) + return c def getNote(self, id): return anki.notes.Note(self, id=id) @@ -767,3 +770,9 @@ and queue = 0""", intTime(), self.usn()) self.db.execute("vacuum") self.db.execute("analyze") self.lock() + + # Logging + ########################################################################## + + def log(self, *args): + runHook("log", args) diff --git a/anki/sched.py b/anki/sched.py index d9f068bcf..485424e3c 100644 --- a/anki/sched.py +++ b/anki/sched.py @@ -55,6 +55,7 @@ class Scheduler(object): self._haveQueues = True def answerCard(self, card, ease): + self.col.log() assert ease >= 1 and ease <= 4 self.col.markReview(card) if self._burySiblingsOnAnswer: @@ -142,14 +143,20 @@ order by due""" % self._deckLimit(), def unburyCards(self): "Unbury cards." self.col.conf['lastUnburied'] = self.today + self.col.log( + self.col.db.list("select id from cards where queue = -2")) self.col.db.execute( "update cards set mod=?,usn=?,queue=type where queue = -2", intTime(), self.col.usn()) def unburyCardsForDeck(self): + sids = ids2str(self.col.decks.active()) + self.col.log( + self.col.db.list("select id from cards where queue = -2 and did in %s" + % sids)) self.col.db.execute( "update cards set mod=?,usn=?,queue=type where queue = -2 and did in %s" - % ids2str(self.col.decks.active()), intTime(), self.col.usn()) + % sids, intTime(), self.col.usn()) # Rev/lrn/time daily stats ########################################################################## @@ -946,12 +953,14 @@ select id from cards where did in %s and queue = 2 and due <= ? limit ?)""" ids = [] return ids # move the cards over + self.col.log(deck['id'], ids) self._moveToDyn(deck['id'], ids) return ids def emptyDyn(self, did, lim=None): if not lim: lim = "did = %s" % did + self.col.log(self.col.db.list("select id from cards where %s" % lim)) # move out of cram queue self.col.db.execute(""" update cards set did = odid, queue = (case when type = 1 then 0 @@ -1242,6 +1251,7 @@ To study outside of the normal schedule, click the Custom Study button below.""" def suspendCards(self, ids): "Suspend cards." + self.col.log(ids) self.remFromDyn(ids) self.removeLrn(ids) self.col.db.execute( @@ -1250,6 +1260,7 @@ To study outside of the normal schedule, click the Custom Study button below.""" def unsuspendCards(self, ids): "Unsuspend cards." + self.col.log(ids) self.col.db.execute( "update cards set queue=type,mod=?,usn=? " "where queue = -1 and id in "+ ids2str(ids), @@ -1259,6 +1270,7 @@ To study outside of the normal schedule, click the Custom Study button below.""" "Bury all cards for note until next session." cids = self.col.db.list( "select id from cards where nid = ? and queue >= 0", nid) + self.col.log(cids) self.removeLrn(cids) self.col.db.execute(""" update cards set queue=-2,mod=?,usn=? where id in """+ids2str(cids), @@ -1295,9 +1307,11 @@ and (queue=0 or (queue=2 and due<=?))""", except ValueError: pass # then bury - self.col.db.execute( - "update cards set queue=-2,mod=?,usn=? where id in "+ids2str(toBury), - intTime(), self.col.usn()) + if toBury: + self.col.db.execute( + "update cards set queue=-2,mod=?,usn=? where id in "+ids2str(toBury), + intTime(), self.col.usn()) + self.col.log(toBury) # Resetting ########################################################################## @@ -1311,6 +1325,7 @@ and (queue=0 or (queue=2 and due<=?))""", "select max(due) from cards where type=0") or 0 # takes care of mod + usn self.sortCards(ids, start=pmax+1) + self.col.log(ids) def reschedCards(self, ids, imin, imax): "Put cards in review queue with a new interval in days (min, max)." @@ -1326,6 +1341,7 @@ and (queue=0 or (queue=2 and due<=?))""", update cards set type=2,queue=2,ivl=:ivl,due=:due, usn=:usn, mod=:mod, factor=:fact where id=:id and odid=0 and queue >=0""", d) + self.col.log(ids) def resetCards(self, ids): "Completely reset cards for export." @@ -1335,6 +1351,7 @@ usn=:usn, mod=:mod, factor=:fact where id=:id and odid=0 and queue >=0""", self.col.db.execute( "update cards set reps=0, lapses=0 where id in " + ids2str(nonNew)) self.forgetCards(nonNew) + self.col.log(ids) # Repositioning new cards ########################################################################## @@ -1377,6 +1394,7 @@ and due >= ? and queue = 0""" % scids, now, self.col.usn(), shiftby, low) d.append(dict(now=now, due=due[nid], usn=self.col.usn(), cid=id)) self.col.db.executemany( "update cards set due=:due,mod=:now,usn=:usn where id = :cid", d) + self.col.log(cids) def randomizeCards(self, did): cids = self.col.db.list("select id from cards where did = ?", did) diff --git a/anki/sync.py b/anki/sync.py index e8a53a002..dec17e0f5 100644 --- a/anki/sync.py +++ b/anki/sync.py @@ -105,6 +105,7 @@ class Syncer(object): # step 1: login & metadata runHook("sync", "login") meta = self.server.meta() + self.col.log("rmeta", meta) if not meta: return "badAuth" rscm = meta['scm'] @@ -125,19 +126,24 @@ class Syncer(object): # and require confirmation if it's non-empty pass meta = self.meta() + self.col.log("lmeta", meta) self.lmod = meta['mod'] self.minUsn = meta['usn'] lscm = meta['scm'] lts = meta['ts'] if abs(rts - lts) > 300: + self.col.log("clock off") return "clockOff" if self.lmod == self.rmod: + self.col.log("no changes") return "noChanges" elif lscm != rscm: + self.col.log("schema diff") return "fullSync" self.lnewer = self.lmod > self.rmod # step 1.5: check collection is valid if not self.col.basicCheck(): + self.col.log("basic check") return "basicCheckFailed" # step 2: deletions runHook("sync", "meta") @@ -154,6 +160,7 @@ class Syncer(object): while 1: runHook("sync", "stream") chunk = self.server.chunk() + self.col.log("server chunk", chunk) self.applyChunk(chunk=chunk) if chunk['done']: break @@ -162,6 +169,7 @@ class Syncer(object): while 1: runHook("sync", "stream") chunk = self.chunk() + self.col.log("client chunk", chunk) self.server.applyChunk(chunk=chunk) if chunk['done']: break @@ -478,6 +486,7 @@ from notes where %s""" % d) for r in data: if r[0] not in lmods or lmods[r[0]] < r[modIdx]: update.append(r) + self.col.log(table, data) return update def mergeCards(self, cards): diff --git a/aqt/main.py b/aqt/main.py index 645b39391..cb7d58ac1 100644 --- a/aqt/main.py +++ b/aqt/main.py @@ -3,6 +3,7 @@ # License: GNU AGPL, version 3 or later; http://www.gnu.org/licenses/agpl.html import os +import pprint import sys import re import traceback @@ -269,7 +270,8 @@ To import into a password protected profile, please open the profile before atte showWarning("""\ Your collection is corrupt. Please see the manual for \ how to restore from a backup.""") - return self.unloadProfile() + self.unloadProfile() + raise self.hideSchemaMsg = False self.progress.setupDB(self.col.db) self.maybeEnableUndo() @@ -837,6 +839,7 @@ the problem and restart Anki.""") def setupHooks(self): addHook("modSchema", self.onSchemaMod) addHook("remNotes", self.onRemNotes) + addHook("log", self.onLog) # Log note deletion ########################################################################## @@ -854,6 +857,22 @@ the problem and restart Anki.""") f.write(("\t".join([str(id), str(mid)] + fields)).encode("utf8")) f.write("\n") + # Debug logging + ########################################################################## + + def onLog(self, args): + def customRepr(x): + if isinstance(x, basestring): + return x + return pprint.pformat(x) + path, num, fn, y = traceback.extract_stack(limit=4)[0] + buf = "[%s] %s:%s(): %s" % (intTime(), os.path.basename(path), fn, + ", ".join([customRepr(x) for x in args])) + lpath = re.sub("\.anki2$", ".log", self.pm.collectionPath()) + open(lpath, "ab").write(buf + "\n") + if os.environ.get("LOG"): + print buf + # Schema modifications ##########################################################################