Coverage for dak/graph

1"""

2Generate an HTML page and PNG charts wih the age of packages in NEW

4To be run once a day.

6The tool stores persistent status in the RRD database and the pickeled queue

7in order to speed up daily runs.

8Directories and database files are created as needed.

10If the RRD directory is deleted the script rebuilds past years from the historical

11logs, and that can take a while, otherwise it just parses fresh data.

12"""

15# License: GPL-2+

16# Tests are in tests/test_graph_new.py

18import os.path

19import pickle

20import subprocess

21import sys

22from collections.abc import Iterator

23from datetime import datetime, timedelta

24from glob import glob

25from os import makedirs

26from textwrap import dedent

28import apt_pkg

29import rrdtool # debdeps: python3-rrdtool

31from daklib import utils

33SECONDS_IN_DAY = 86400

34debug_mode = False

37def debug(msg: str) -> None:

38 """Verbose messages for debugging"""

39 if debug_mode: 39 ↛ 40line 39 didn't jump to line 40 because the condition on line 39 was never true

40 print(msg)

43def write_index(out_dir: str) -> None:

44 """Generates index.html page in the output directory"""

45 index_html = """

46<!DOCTYPE html>

47<html lang="en">

48 <head>

49 <meta charset="utf-8" />

50 <link rel="shortcut icon" href="https://www.debian.org/favicon.ico" />

51 <title>Debian NEW queue</title>

52 </head>

53 <body>

54 How much time a new package spends in the NEW queue.

55 Divided in percentiles: 0 (aka age of the oldest package), 50 (aka median) and 99

57 <img src="new_queue_wait_time_all.png">

58

59 <img src="new_queue_wait_time_year.png">

60

61 <img src="new_queue_wait_time_month.png">

62

63 Generated on {}

64 </body>

65</html>

66"""

67 fname = os.path.join(out_dir, "index.html")

68 with open(fname, "w") as f:

69 f.write(index_html.format(datetime.utcnow()))

72def init_rrd(rrdfn: str, t: datetime) -> None:

73 """Initialize empty RRD"""

74 print(f"RRD file {rrdfn} not found. Initializing it now.")

75 rrdtool.create(

76 rrdfn,

77 "--start",

78 t.strftime("%s"),

79 "--step",

80 str(SECONDS_IN_DAY), # 1 update per day

81 "DS:p0:GAUGE:172800:U:U", # 0 percentile

82 "DS:p50:GAUGE:172800:U:U", # 50 percentile

83 "DS:p99:GAUGE:172800:U:U", # 99 percentile

84 "RRA:AVERAGE:0.5:1:3650",

85 )

88def gen_stats(t: datetime, q: dict) -> tuple:

89 """Extract percentiles of package ages"""

90 s = sorted(q.values())

91 p99 = t - s[int(len(s) * 0.50)]

92 p50 = t - s[int(len(s) * 0.05)]

93 p0 = t - s[int(len(s) * 0.02)]

94 return (p0, p50, p99)

97def plot_graph(

98 out_dir: str, fname: str, rrdfn: str, start, end: datetime, title: str

99) -> None:

100 fname = os.path.join(out_dir, fname)

101 print(f"Writing {fname}")

102 args = (

103 "--start",

104 start.strftime("%s"),

105 "--end",

106 end.strftime("%s"),

107 "--width",

108 "900",

109 "--height",

110 "200",

111 "--title",

112 "Days spent in NEW over {}".format(title),

113 "-v",

114 "days",

115 f"DEF:p0={rrdfn}:p0:AVERAGE",

116 f"DEF:p50={rrdfn}:p50:AVERAGE",

117 f"DEF:p99={rrdfn}:p99:AVERAGE",

118 "LINE1:p0#FF8080:0 percentile",

119 "LINE2:p50#8F8080:50 percentile",

120 "LINE3:p99#8FFF80:99 percentile",

121 )

122 # print(" ".join(args))

123 rrdtool.graph(fname, *args)

124

125

126def _handle_conf() -> tuple:

127 """Load configuration parameters from Cnf"""

128 Cnf = utils.get_conf()

129 Arguments = [

130 ("h", "help", "GraphNew::Options::Help"),

131 ("r", "rrd", "GraphNew::Options::Rrd", "HasArg"),

132 ("o", "outdir", "GraphNew::Options::Outdir", "HasArg"),

133 ("b", "dak_base_dir", "Dir::Base", "HasArg"),

134 ]

135 apt_pkg.parse_commandline(Cnf, Arguments, sys.argv) # type: ignore[attr-defined]

136

137 try:

138 Options = Cnf.subtree("GraphNew::Options") # type: ignore[attr-defined]

139 except KeyError:

140 msg = dedent(

141 """

142 The GraphNew::Options subtree is missing from the config file

143 Please use --rrd ... --outdir ... (see --help) or add:

144

145 GraphNew

146 {

147 Options

148 {

149 Rrd "<RRD directory>";

150 Outdir "<HTML output directory>";

151 }

152 }

153 """

154 )

155 print(msg, file=sys.stderr)

156 sys.exit(1)

157

158 if "Help" in Options:

159 usage()

160

161 if "GraphNew::Options::Rrd" in Cnf:

162 rrd_dir = Cnf["GraphNew::Options::Rrd"]

163 elif "Dir::Rrd" in Cnf:

164 rrd_dir = Cnf["Dir::Rrd"]

165 else:

166 print("No RRD directory configured.\n", file=sys.stderr)

167 sys.exit(1)

168

169 try:

170 outdir = Cnf["GraphNew::Options::Outdir"]

171 except Exception:

172 print("No output directory configured\n", file=sys.stderr)

173 sys.exit(1)

174

175 log_dir = Cnf.get("Dir::Log")

176 assert log_dir, "Dir::Log is missing from dak.conf or empty"

177 return rrd_dir, outdir, log_dir

178

179

180def skip_file(fn: str, last_update) -> bool:

181 """Skip files that are already processed"""

182 if last_update is None:

183 return False

184 fn = os.path.split(fn)[1]

185 basename, ext = os.path.splitext(fn)

186 if ext == "":

187 return False # always process last, uncompressed file

188 filetime = datetime.strptime(basename, "%Y-%m")

189 return filetime < last_update

190

191

192def extract_queue_events(log_dir: str, last_update: datetime | None) -> Iterator[tuple]:

193 """Extracts NEW queue events from log files"""

194 compressed_glob = os.path.join(log_dir, "20*xz")

195 debug(f"Scanning for compressed logfiles using glob '{compressed_glob}'")

196 compressed_fns = sorted(glob(compressed_glob))

197 fns = compressed_fns[5:] # 5 oldest logfiles have no events

198 current_fn = os.path.join(log_dir, datetime.utcnow().strftime("%Y-%m"))

199 debug(f"Also adding uncompressed log {current_fn}")

200 fns.append(current_fn)

201 print("%d files to process" % len(fns))

202 events_per_month_cnt = None

203 for fn in fns:

204 if skip_file(fn, last_update):

205 debug(f"Skipping {fn}")

206 continue

207

208 if events_per_month_cnt is not None:

209 debug(f"Events in the month: {events_per_month_cnt}")

210

211 events_per_month_cnt = 0

212 debug(f"Processing {fn}")

213 cmd = (

214 """xzgrep -h -e ACCEPT-TO-NEW -e "|NEW ACCEPT|" -e "|REJECT|" """

215 f"""-e "|NEW REJECT|" -e "|Policy Queue " {fn}"""

216 )

217 data = subprocess.check_output(cmd, shell=True).decode()

218 for line in data.splitlines():

219 line = line.rstrip()

220 if line.startswith("#"):

221 continue

222 try:

223 # <timestamp> <stage> <actor> <event> ...

224 ts, _, _, event, remaining = line.split("|", 4)

225 except ValueError:

226 continue

227

228 if event == "exception":

229 # Seem to have logged a python exception, ignore

230 continue

231 elif event.startswith("Policy Queue "):

232 _, pname = remaining.split("|", 1)

233 else:

234 pname = remaining

235

236 assert "|" not in pname, repr(line)

237 assert len(ts) == 14

238

239 event_time = datetime.strptime(ts, "%Y%m%d%H%M%S")

240 events_per_month_cnt += 1

241 yield pname, event, event_time

242

243

244def process_events(

245 events, last_update: datetime | None, init_time: datetime | None, queue

246) -> tuple:

247 """Process logged events like ACCEPT-TO-NEW, ACCEPT, REJECT and

248 update the RRD database accordingly"""

249 glitch_cnt = 0

250 processed_events_cnt = 0

251 previous_day = None

252 rrdtool_updates = []

253 for pname, event, event_time in events:

254 if last_update and last_update >= event_time: 254 ↛ 255line 254 didn't jump to line 255 because the condition on line 254 was never true

255 continue

256

257 processed_events_cnt += 1

258 if init_time is None:

259 # Initialise RRD once

260 i = event_time - timedelta(days=1)

261 debug(f"Very first event at: {event_time}")

262 init_time = i

263 previous_day = event_time.date()

264

265 pname = pname.rsplit(".", 1)[0]

266

267 # Update queue dict

268 exit_events = {

269 "NEW ACCEPT",

270 "NEW REJECT",

271 "Policy Queue ACCEPT",

272 "REJECT",

273 "Policy Queue REJECT",

274 }

275 if event == "ACCEPT-TO-NEW":

276 queue[pname] = event_time

277 elif event in exit_events: 277 ↛ 283line 277 didn't jump to line 283 because the condition on line 277 was always true

278 # Approved or rejected, exits NEW

279 if pname in queue:

280 queue.pop(pname)

281 else:

282 glitch_cnt += 1

283 elif event == "ACCEPT":

284 pass

285

286 if event_time.date() != previous_day:

287 # On day change run statistics, update RRD and queue.pickle file

288 stats = gen_stats(event_time, queue)

289 ux = event_time.strftime("%s")

290 v = f"{ux}:{stats[0].days}:{stats[1].days}:{stats[2].days}"

291 rrdtool_updates.append(v)

292

293 previous_day = event_time.date()

294

295 debug(f"glitches count: {glitch_cnt}")

296 debug(f"processed events count: {processed_events_cnt}")

297 debug(f"queue len: {len(queue)}")

298 return rrdtool_updates, init_time

299

300

301def generate_output(rrdfn: str, out_dir: str, init_time) -> None:

302 """Generate png charts and index.html in the output directory"""

303 end_time = rrdtool.lastupdate(rrdfn)["date"]

304 ofn = "new_queue_wait_time_all.png"

305 plot_graph(out_dir, ofn, rrdfn, init_time, end_time, "all")

306

307 start_time = end_time - timedelta(days=365)

308 ofn = "new_queue_wait_time_year.png"

309 plot_graph(out_dir, ofn, rrdfn, start_time, end_time, "one year")

310

311 start_time = end_time - timedelta(days=30)

312 ofn = "new_queue_wait_time_month.png"

313 plot_graph(out_dir, ofn, rrdfn, start_time, end_time, "one month")

314 write_index(out_dir)

315

316

317def main(verbose_debug=False) -> None:

318 global debug_mode

319 debug_mode = verbose_debug

320 rrd_dir, out_dir, log_dir = _handle_conf()

321 makedirs(rrd_dir, exist_ok=True)

322 makedirs(out_dir, exist_ok=True)

323 rrdfn = os.path.join(rrd_dir, "graph_new.rrd")

324 queue_fn = os.path.join(rrd_dir, "graph_new.pickle")

325 init_time: datetime | None = None

326 last_update: datetime | None = None

327 if os.path.isfile(rrdfn):

328 init_time = datetime.fromtimestamp(rrdtool.first(rrdfn))

329 last_update = rrdtool.lastupdate(rrdfn)["date"]

330 with open(queue_fn, "rb") as f:

331 queue = pickle.load(f)

332 else:

333 queue = {}

334

335 events = tuple(extract_queue_events(log_dir, last_update))

336 print(f"{len(events)} events to process")

337 if events:

338 debug(f"First event to process at: {events[0][2]}")

339

340 rrdtool_updates, begin_time = process_events(events, last_update, init_time, queue)

341 if rrdtool_updates:

342 debug(f"First RRD update: {rrdtool_updates[0]}")

343

344 with open(queue_fn, "wb") as f:

345 pickle.dump(queue, f)

346

347 if init_time is None:

348 assert begin_time, "This happens only if no events are found at all"

349 init_time = begin_time

350 init_rrd(rrdfn, begin_time)

351

352 for u in rrdtool_updates:

353 rrdtool.update(rrdfn, u)

354

355 generate_output(rrdfn, out_dir, init_time)

356

357

358def usage(exit_code=0) -> None:

359 msg = dedent(

360 """\

361 Usage: dak graph-new

362 Graphs the age of packages in the NEW queue.

363

364 -h, --help show this help and exit.

365 -r, --rrd=key Directory where rrd files to be updated are stored

366 -o, --outdir=key Directory where the output is stored

367 """

368 )

369 print(msg)

370 sys.exit(exit_code)

Coverage for dak/graph_new.py: 30%

189 statements