Hide keyboard shortcuts

Hot-keys on this page

r m x p   toggle line displays

j k   next/prev highlighted chunk

0   (zero) top of page

1   (one) first highlighted chunk

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

31

32

33

34

35

36

37

38

39

40

41

42

43

44

45

46

47

48

49

50

51

52

53

54

55

56

57

58

59

60

61

62

63

64

65

66

67

68

69

70

71

72

73

74

75

76

77

78

79

80

81

82

83

84

85

86

87

88

89

90

91

92

93

94

95

96

97

98

99

100

101

102

103

104

105

106

107

108

109

110

111

112

113

114

115

116

117

118

119

120

121

122

123

124

125

126

127

128

129

130

131

132

133

134

135

136

137

138

139

140

141

142

143

144

145

146

147

148

149

150

151

152

153

154

155

156

157

158

159

160

161

162

163

164

165

166

167

168

169

170

171

172

173

174

175

176

177

178

179

180

181

182

183

184

185

186

187

188

189

190

191

192

193

194

195

196

197

198

199

200

201

202

203

204

205

206

207

208

209

210

211

212

213

214

215

216

217

218

219

220

221

222

223

224

225

226

227

228

229

230

231

232

233

234

235

236

237

238

239

240

241

242

243

244

245

246

247

248

249

250

251

252

253

254

255

256

257

258

259

260

261

262

263

264

265

266

267

268

269

270

271

272

273

274

275

276

277

278

279

280

281

282

283

284

285

286

287

288

289

290

291

292

293

294

295

296

297

298

299

300

301

302

303

304

305

306

307

308

309

310

311

312

313

314

315

316

317

318

319

320

321

322

323

324

325

326

327

328

329

330

331

332

333

334

335

336

337

338

339

340

341

342

343

344

345

346

347

348

349

350

351

352

353

354

355

356

357

358

359

360

361

362

363

364

365

366

367

368

369

370

371

372

373

374

375

376

377

378

379

380

381

382

383

384

385

386

387

388

389

390

391

392

393

394

395

""" 

C Function Profiler Using Google Perftools 

 

Note that the profiler samples 100x per second by default. In 

particular, you cannot profile anything shorter than 10ms. You can 

adjust the rate with the ``CPUPROFILE_FREQUENCY`` environment variable 

if you want to change it. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler, run_100ms 

sage: prof = Profiler() 

sage: prof.start() # optional - gperftools 

sage: run_100ms() 

sage: prof.stop() # optional - gperftools 

PROFILE: interrupts/evictions/bytes = ... 

 

REFERENCE: 

 

Uses the `Google performance analysis tools 

<https://github.com/gperftools/gperftools>`_. Note that they are not 

included in Sage, you have to install them yourself on your system. 

 

AUTHORS: 

 

- Volker Braun (2014-03-31): initial version 

""" 

 

#***************************************************************************** 

# Copyright (C) 2014 Volker Braun <vbraun.name@gmail.com> 

# 

# Distributed under the terms of the GNU General Public License (GPL) 

# 

# http://www.gnu.org/licenses/ 

#***************************************************************************** 

 

import ctypes 

import time 

from sage.structure.sage_object import SageObject 

from sage.misc.cachefunc import cached_method 

from sage.misc.compat import find_library 

 

 

libc = None 

libprofiler = None 

 

 

 

class Profiler(SageObject): 

 

def __init__(self, filename=None): 

""" 

Interface to the gperftools profiler 

 

INPUT: 

 

- ``filename`` -- string or ``None`` (default). The file name 

to log to. By default, a new temporary file is created. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: Profiler() 

Profiler logging to ... 

""" 

if filename is None: 

from sage.misc.temporary_file import tmp_filename 

self._filename = tmp_filename(ext='.perf') 

else: 

self._filename = filename 

 

def filename(self): 

""" 

Return the file name 

 

OUTPUT: 

 

String. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: prof = Profiler() 

sage: prof.filename() 

'.../tmp_....perf' 

""" 

return self._filename 

 

def _repr_(self): 

""" 

Return string representation 

 

OUTPUT: 

 

String. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: Profiler() 

Profiler logging to .../tmp....perf 

""" 

return 'Profiler logging to {0}'.format(self.filename()) 

 

def _libc(self): 

""" 

Return libc 

 

OUTPUT: 

 

A ctypes shared library handle. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: Profiler()._libc() 

<CDLL '...', handle ... at ...> 

""" 

global libc 

if libc is not None: 

return libc 

name = find_library('c') 

if name: 

libc = ctypes.CDLL(name) 

return libc 

else: 

raise ImportError('failed to open libc') 

 

def _libprofiler(self): 

""" 

Return libprofiler 

 

OUTPUT: 

 

A ctypes shared library handle. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: Profiler()._libprofiler() # optional - gperftools 

<CDLL 'libprofiler...', handle ... at ...> 

""" 

global libprofiler 

if libprofiler is not None: 

return libprofiler 

import ctypes, ctypes.util 

name = ctypes.util.find_library('profiler') 

if name: 

libprofiler = ctypes.CDLL(name) 

return libprofiler 

else: 

raise ImportError('failed to open libprofiler, make sure gperftools is installed') 

 

def start(self): 

""" 

Start profiling 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler, run_100ms 

sage: prof = Profiler() 

sage: prof.start() # optional - gperftools 

sage: run_100ms() 

sage: prof.stop() # optional - gperftools 

PROFILE: interrupts/evictions/bytes = ... 

""" 

from signal import SIGPROF, SIG_DFL 

self._previous_sigprof_handler = self._libc().signal(SIGPROF, SIG_DFL) 

profiler = self._libprofiler() 

self._t_start = time.time() 

rc = profiler.ProfilerStart(self.filename()) 

if rc < 0: 

raise ValueError('profiler failed to start') 

 

def stop(self): 

""" 

Stop the CPU profiler 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler, run_100ms 

sage: prof = Profiler() 

sage: prof.start() # optional - gperftools 

sage: run_100ms() 

sage: prof.stop() # optional - gperftools 

PROFILE: interrupts/evictions/bytes = ... 

""" 

profiler = self._libprofiler() 

profiler.ProfilerStop() 

self._t_stop = time.time() 

if (self._t_stop - self._t_start) < 0.1: 

from warnings import warn 

warn('not enough samples, total runtime was ' 

'less than 100ms', RuntimeWarning) 

 

@cached_method 

def _pprof(self): 

""" 

Return the name of the ``pprof`` binary. 

 

OUTPUT: 

 

String. The name of the gperftools ``pprof`` utility. A 

``OSError`` is raised if it cannot be found. 

 

EXAMPLES:: 

 

sage: import six 

sage: from sage.misc.gperftools import Profiler 

sage: prof = Profiler() 

sage: try: 

....: pp = prof._pprof() 

....: assert isinstance(pp, six.string_types) 

....: except OSError: 

....: pass # not installed 

""" 

potential_names = ['google-pprof', 'pprof'] 

from subprocess import check_output, CalledProcessError, STDOUT 

for name in potential_names: 

try: 

version = check_output([name, '--version'], stderr=STDOUT) 

except (CalledProcessError, OSError): 

continue 

if 'gperftools' not in version: 

from warnings import warn 

warn('the "{0}" utility does not appear to be the gperftools profiler' 

.format(name), RuntimeWarning) 

continue 

return name 

raise OSError('unable to run pprof, please install gperftools') 

 

def _executable(self): 

""" 

Return the name of the Sage Python interpreter. 

 

OUTPUT: 

 

String. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: prof = Profiler() 

sage: prof._executable() 

'.../python...' 

""" 

import sys 

return sys.executable 

 

def _call_pprof(self, *args, **kwds): 

""" 

Run the pprof binary 

 

INPUT: 

 

- ``args`` -- list of strings. The arguments to ``pprof``. 

 

- ``kwds`` -- keyword arguments passed to 

``subprocess.check_call``. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: prof = Profiler() 

sage: prof._call_pprof('--help') # optional - gperftools 

Usage: 

pprof [options] <program> <profiles> 

... 

""" 

from subprocess import check_call 

check_call([self._pprof()] + list(args), **kwds) 

 

def top(self, cumulative=True): 

""" 

Print text report 

 

OUTPUT: 

 

Nothing. A textual report is printed to stdout. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler 

sage: prof = Profiler() 

sage: prof.start() # optional - gperftools 

sage: # do something 

sage: prof.stop() # optional - gperftools 

PROFILE: interrupts/evictions/bytes = ... 

sage: prof.top() # optional - gperftools 

Using local file ... 

Using local file ... 

""" 

args = [] 

if cumulative: 

args += ['--cum'] 

args += ['--text', self._executable(), self.filename()] 

self._call_pprof(*args) 

 

def save(self, filename, cumulative=True, verbose=True): 

""" 

Save report to disk. 

 

INPUT: 

 

- ``filename`` -- string. The filename to save at. Must end 

with one of ``.dot``, ``.ps``, ``.pdf``, ``.svg``, ``.gif``, 

or ``.txt`` to specify the output file format. 

 

- ``cumulative`` -- boolean (optional, default: 

``True``). Whether to return cumulative timings. 

 

- ``verbose`` -- boolean (optional, default: 

``True``). Whether to print informational messages. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import Profiler, run_100ms 

sage: prof = Profiler() 

sage: prof.start() # optional - gperftools 

sage: run_100ms() # optional - gperftools 

sage: prof.stop() # optional - gperftools 

PROFILE: interrupts/evictions/bytes = ... 

sage: f = tmp_filename(ext='.txt') # optional - gperftools 

sage: prof.save(f, verbose=False) # optional - gperftools 

""" 

args = [] 

if cumulative: 

args += ['--cum'] 

if filename.endswith('.dot'): 

args += ['--dot'] 

elif filename.endswith('.ps'): 

args += ['--ps'] 

elif filename.endswith('.pdf'): 

args += ['--pdf'] 

elif filename.endswith('.svg'): 

args += ['--svg'] 

elif filename.endswith('.txt'): 

args += ['--text'] 

elif filename.endswith('.gif'): 

args += ['--gif'] 

else: 

raise ValueError('unknown extension') 

args += [self._executable(), self.filename()] 

stderr = sys.stdout if verbose else False 

with open(filename, 'wb') as outfile: 

self._call_pprof(*args, stdout=outfile, stderr=stderr) 

 

 

def crun(s, evaluator): 

""" 

Profile single statement. 

 

- ``s`` -- string. Sage code to profile. 

 

- ``evaluator`` -- callable to evaluate. 

 

EXAMPLES:: 

 

sage: import sage.misc.gperftools as gperf 

sage: ev = lambda ex:eval(ex, globals(), locals()) 

sage: gperf.crun('gperf.run_100ms()', evaluator=ev) # optional - gperftools 

PROFILE: interrupts/evictions/bytes = ... 

Using local file ... 

Using local file ... 

""" 

prof = Profiler() 

from sage.repl.preparse import preparse 

py_s = preparse(s) 

prof.start() 

try: 

evaluator(py_s) 

finally: 

prof.stop() 

prof.top() 

 

 

def run_100ms(): 

""" 

Used for doctesting. 

 

A function that performs some computation for more than (but not 

that much more than) 100ms. 

 

EXAMPLES:: 

 

sage: from sage.misc.gperftools import run_100ms 

sage: run_100ms() 

""" 

t0 = time.time() # start 

t1 = t0 + 0.1 # end 

from sage.misc.functional import symbolic_sum 

from sage.symbolic.ring import SR 

while time.time() < t1: 

sum(1/(1+SR(n) ** 2) for n in range(100))