Skip to content

Commit 2f64d27

Browse files
kmnhankmnhan
authored
Fix performance overhead due to logging (#21)
* fix: properly detect logging level * perf: eliminate string formatting overhead in logging calls * style: apply autopep8
1 parent 43fccf5 commit 2f64d27

5 files changed

Lines changed: 81 additions & 80 deletions

File tree

‎igor2/binarywave.py‎

Lines changed: 34 additions & 34 deletions
Original file line numberDiff line numberDiff line change
@@ -419,8 +419,8 @@ def unpack(self, stream):
419419
)
420420
except BaseException:
421421
logger.error(
422-
'could not reshape data from {} to {}'.format(
423-
self.shape, data_b))
422+
'could not reshape data from %s to %s',
423+
self.shape, data_b)
424424
raise
425425
return data
426426

@@ -602,8 +602,8 @@ def post_unpack(self, parents, data):
602602
wdata = wdata.reshape(shape)
603603
except ValueError:
604604
logger.error(
605-
'could not reshape strings from {} to {}'.format(
606-
shape, wdata.shape))
605+
'could not reshape strings from %s to %s',
606+
shape, wdata.shape)
607607
raise
608608
wave_data['wData'] = wdata
609609

@@ -620,8 +620,8 @@ def post_unpack(self, parents, data):
620620
need_to_reorder_bytes = _need_to_reorder_bytes(version)
621621
wave_structure.byte_order = _byte_order(need_to_reorder_bytes)
622622
logger.debug(
623-
'get byte order from version: {} (reorder? {})'.format(
624-
wave_structure.byte_order, need_to_reorder_bytes))
623+
'get byte order from version: %s (reorder? %s)',
624+
wave_structure.byte_order, need_to_reorder_bytes)
625625
else:
626626
need_to_reorder_bytes = False
627627

@@ -639,8 +639,8 @@ def post_unpack(self, parents, data):
639639
'invalid binary wave version: {}'.format(version))
640640

641641
if wave_structure.fields[-1].format != old_format:
642-
logger.debug('change wave headers from {} to {}'.format(
643-
old_format, wave_structure.fields[-1].format))
642+
logger.debug('change wave headers from %s to %s',
643+
old_format, wave_structure.fields[-1].format)
644644
wave_structure.setup()
645645
elif need_to_reorder_bytes:
646646
wave_structure.setup()
@@ -758,40 +758,40 @@ def post_unpack(self, parents, data):
758758
name='Wave5',
759759
fields=[
760760
_Field(
761-
BinHeader5, 'bin_header',
762-
help='Binary wave header'),
761+
BinHeader5, 'bin_header',
762+
help='Binary wave header'),
763763
_Field(
764-
WaveHeader5, 'wave_header',
765-
help='Wave header'),
764+
WaveHeader5, 'wave_header',
765+
help='Wave header'),
766766
DynamicWaveDataField5(
767-
'f', 'wData',
768-
help='The start of the array of waveform data.',
769-
count=0, array=True),
767+
'f', 'wData',
768+
help='The start of the array of waveform data.',
769+
count=0, array=True),
770770
DynamicDependencyFormulaField(
771-
'c', 'formula',
772-
help='Optional wave dependency formula.',
773-
count=0, array=True),
771+
'c', 'formula',
772+
help='Optional wave dependency formula.',
773+
count=0, array=True),
774774
DynamicWaveNoteField(
775-
'c', 'note',
776-
help='Optional wave note data.', count=0,
777-
array=True),
775+
'c', 'note',
776+
help='Optional wave note data.', count=0,
777+
array=True),
778778
DynamicDataUnitsField(
779-
'c', 'data_units',
780-
help='Optional extended data units data.',
781-
count=0, array=True),
779+
'c', 'data_units',
780+
help='Optional extended data units data.',
781+
count=0, array=True),
782782
DynamicDimensionUnitsField(
783-
'c', 'dimension_units',
784-
help='Optional dimension label data',
785-
count=0, array=True),
783+
'c', 'dimension_units',
784+
help='Optional dimension label data',
785+
count=0, array=True),
786786
DynamicLabelsField(
787-
'c', 'labels',
788-
help="Optional dimension label data",
789-
count=0, array=True),
787+
'c', 'labels',
788+
help="Optional dimension label data",
789+
count=0, array=True),
790790
DynamicStringIndicesDataField(
791-
'P', 'sIndices',
792-
help='Dynamic string indices for text waves.',
793-
count=0, array=True),
794-
])
791+
'P', 'sIndices',
792+
help='Dynamic string indices for text waves.',
793+
count=0, array=True),
794+
])
795795

796796
Wave = _DynamicStructure(
797797
name='Wave',

‎igor2/cli/script.py‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -72,7 +72,7 @@ def plot_wave(self, args, wave, title=None):
7272
try:
7373
axes.plot(wave['wave']['wData'], 'r.')
7474
except ValueError as error:
75-
logger.error('error plotting {}: {}'.format(title, error))
75+
logger.error('error plotting %s: %s', title, error)
7676
pass
7777
self._num_plots += 1
7878

‎igor2/packed.py‎

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -66,7 +66,7 @@ def load(filename, strict=True, ignore_unknown=True, initial_byte_order=None):
6666
filesystem : dict
6767
The filesystem structure of the packed experiment file.
6868
"""
69-
logger.debug('loading a packed experiment file from {}'.format(filename))
69+
logger.debug('loading a packed experiment file from %s', filename)
7070
records = []
7171
if hasattr(filename, 'read'):
7272
f = filename # filename is actually a stream object
@@ -92,14 +92,14 @@ def load(filename, strict=True, ignore_unknown=True, initial_byte_order=None):
9292
need_to_reorder = _need_to_reorder_bytes(header['version'])
9393
byte_order = initial_byte_order = _byte_order(need_to_reorder)
9494
logger.debug(
95-
'get byte order from version: {} (reorder? {})'.format(
96-
byte_order, need_to_reorder))
95+
'get byte order from version: %s (reorder? %s)',
96+
byte_order, need_to_reorder)
9797
if need_to_reorder:
9898
PackedFileRecordHeader.byte_order = byte_order
9999
PackedFileRecordHeader.setup()
100100
header = PackedFileRecordHeader.unpack_from(b)
101101
logger.debug(
102-
'reordered version: {}'.format(header['version']))
102+
'reordered version: %s', header['version'])
103103
data = bytes(f.read(header['numDataBytes']))
104104
if len(data) < header['numDataBytes']:
105105
raise ValueError(
@@ -108,16 +108,16 @@ def load(filename, strict=True, ignore_unknown=True, initial_byte_order=None):
108108
).format(len(b), header['numDataBytes']))
109109
record_type = _RECORD_TYPE.get(
110110
header['recordType'] & PACKEDRECTYPE_MASK, _UnknownRecord)
111-
logger.debug('the new record has type {} ({}).'.format(
112-
record_type, header['recordType']))
111+
logger.debug('the new record has type %s (%s).',
112+
record_type, header['recordType'])
113113
if record_type in [_UnknownRecord, _UnusedRecord
114114
] and not ignore_unknown:
115115
raise KeyError('unkown record type {}'.format(
116116
header['recordType']))
117117
records.append(record_type(header, data, byte_order=byte_order))
118118
finally:
119-
logger.debug('finished loading {} records from {}'.format(
120-
len(records), filename))
119+
logger.debug('finished loading %s records from %s',
120+
len(records), filename)
121121
if not hasattr(filename, 'read'):
122122
f.close()
123123

‎igor2/record/variables.py‎

Lines changed: 7 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -292,8 +292,8 @@ def post_unpack(self, parents, data):
292292
need_to_reorder_bytes = _need_to_reorder_bytes(version)
293293
variables_structure.byte_order = _byte_order(need_to_reorder_bytes)
294294
logger.debug(
295-
'get byte order from version: {} (reorder? {})'.format(
296-
variables_structure.byte_order, need_to_reorder_bytes))
295+
'get byte order from version: %s (reorder? %s)',
296+
variables_structure.byte_order, need_to_reorder_bytes)
297297
else:
298298
need_to_reorder_bytes = False
299299

@@ -307,8 +307,9 @@ def post_unpack(self, parents, data):
307307
'invalid variables record version: {}'.format(version))
308308

309309
if variables_structure.fields[-1].format != old_format:
310-
logger.debug('change variables record from {} to {}'.format(
311-
old_format, variables_structure.fields[-1].format))
310+
logger.debug('change variables record from %s to %s',
311+
old_format, variables_structure.fields[-1].format)
312+
312313
variables_structure.setup()
313314
elif need_to_reorder_bytes:
314315
variables_structure.setup()
@@ -340,6 +341,6 @@ def __init__(self, *args, **kwargs):
340341
self.namespace = {}
341342
for key, value in self.variables['variables'].items():
342343
if key not in ['var_header']:
343-
logger.debug('update namespace {} with {} for {}'.format(
344-
self.namespace, value, key))
344+
logger.debug('update namespace %s with %s for %s',
345+
self.namespace, value, key)
345346
self.namespace.update(value)

‎igor2/struct.py‎

Lines changed: 31 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,6 @@
88
from __future__ import absolute_import
99
import io as _io
1010
import logging
11-
import pprint as _pprint
1211
import struct as _struct
1312

1413
import numpy as _numpy
@@ -147,7 +146,7 @@ def setup(self):
147146
Use this method to recalculate dynamic properities after
148147
changing the basic properties set during initialization.
149148
"""
150-
logger.debug('setup {}'.format(self))
149+
logger.debug('setup %s', self)
151150
self.item_count = _numpy.prod(self.count) # number of item repeats
152151
if not self.array and self.item_count != 1:
153152
raise ValueError(
@@ -244,7 +243,7 @@ def pack_item(self, item=None):
244243

245244
def unpack_data(self, data):
246245
"""Inverse of .pack_data"""
247-
logger.debug('unpack {} for {} {}'.format(data, self, self.format))
246+
logger.debug('unpack %s for %s %s', data, self, self.format)
248247
iterator = iter(data)
249248
try:
250249
items = [next(iterator) for i in range(self.arg_count)]
@@ -279,8 +278,8 @@ def unpack_data(self, data):
279278
raise NotImplementedError('reshape Structure field')
280279
else:
281280
unpacked = _numpy.array(unpacked)
282-
logger.debug('reshape {} data from {} to {}'.format(
283-
self, unpacked.shape, count))
281+
logger.debug('reshape %s data from %s to %s',
282+
self, unpacked.shape, count)
284283
unpacked = unpacked.reshape(count)
285284
return unpacked
286285

@@ -492,14 +491,14 @@ def setup(self):
492491
Use this method to recalculate dynamic properities after
493492
changing the basic properties set during initialization.
494493
"""
495-
logger.debug('setup {!r}'.format(self))
494+
logger.debug('setup %r', self)
496495
self.set_byte_order(self.byte_order)
497496
self.get_format()
498497

499498
def set_byte_order(self, byte_order):
500499
"""Allow changing the format byte_order on the fly.
501500
"""
502-
logger.debug('set byte order for {!r} to {}'.format(self, byte_order))
501+
logger.debug('set byte order for %r to %s', self, byte_order)
503502
self.byte_order = byte_order
504503
for field in self.fields:
505504
if isinstance(field.format, Structure):
@@ -517,7 +516,7 @@ def get_format(self):
517516
return format
518517

519518
def sub_format(self):
520-
logger.debug('calculate sub-format for {!r}'.format(self))
519+
logger.debug('calculate sub-format for %r', self)
521520
for field in self.fields:
522521
if isinstance(field.format, Structure):
523522
field_format = list(
@@ -579,8 +578,8 @@ def unpack(self, *args, **kwargs):
579578

580579
def unpack_from(self, buffer, offset=0, *args, **kwargs):
581580
logger.debug(
582-
'unpack {!r} for {!r} ({}, offset={}) with {} ({})'.format(
583-
buffer, self, len(buffer), offset, self.format, self.size))
581+
'unpack %r for %r (%s, offset=%s) with %s (%s)',
582+
buffer, self, len(buffer), offset, self.format, self.size)
584583
args = super(Structure, self).unpack_from(
585584
buffer, offset, *args, **kwargs)
586585
return self._unpack_item(args)
@@ -595,8 +594,8 @@ def __init__(self, stream):
595594

596595
def read(self, size):
597596
data = self.stream.read(size)
598-
logger.debug('read {} from {}: ({}) {!r}'.format(
599-
size, self.stream, len(data), data))
597+
logger.debug('read %s from %s: (%s) %r',
598+
size, self.stream, len(data), data)
600599
return data
601600

602601

@@ -698,10 +697,10 @@ def _pre_pack(self, parents=None, data=None):
698697
parents = parents + [self]
699698
for f in self.fields:
700699
if hasattr(f, 'pre_pack'):
701-
logger.debug('pre-pack {}'.format(f))
700+
logger.debug('pre-pack %s', f)
702701
f.pre_pack(parents=parents, data=data)
703702
if isinstance(f.format, DynamicStructure):
704-
logger.debug('pre-pack {!r}'.format(f.format))
703+
logger.debug('pre-pack %r', f.format)
705704
f._pre_pack(parents=parents, data=data)
706705

707706
def pack(self, data):
@@ -720,22 +719,23 @@ def unpack_stream(self, stream, parents=None, data=None, d=None):
720719
if data is None:
721720
parents = [self]
722721
data = d = {}
723-
if logger.level <= logging.DEBUG:
722+
if logger.isEnabledFor(logging.DEBUG):
724723
stream = DebuggingStream(stream)
725724
else:
726725
parents = parents + [self]
727726

728727
for f in self.fields:
729-
logger.debug('parsing {!r}.{} (count={}, item_count={})'.format(
730-
self, f, f.count, f.item_count))
731-
if logger.level <= logging.DEBUG:
732-
logger.debug('data:\n{}'.format(_pprint.pformat(data)))
728+
logger.debug('parsing %r.%s (count=%s, item_count=%s)',
729+
self, f, f.count, f.item_count)
730+
if logger.isEnabledFor(logging.DEBUG):
731+
import pprint as _pprint
732+
logger.debug('data:\n%s', _pprint.pformat(data))
733733
if hasattr(f, 'pre_unpack'):
734-
logger.debug('pre-unpack {}'.format(f))
734+
logger.debug('pre-unpack %s', f)
735735
f.pre_unpack(parents=parents, data=data)
736736

737737
if hasattr(f, 'unpack'): # override default unpacking
738-
logger.debug('override unpack for {}'.format(f))
738+
logger.debug('override unpack for %s', f)
739739
d[f.name] = f.unpack(stream)
740740
continue
741741

@@ -758,15 +758,15 @@ def unpack_stream(self, stream, parents=None, data=None, d=None):
758758
f.format.unpack_stream(
759759
stream, parents=parents, data=data, d=d[f.name])
760760
if hasattr(f, 'post_unpack'):
761-
logger.debug('post-unpack {}'.format(f))
761+
logger.debug('post-unpack %s', f)
762762
repeat = f.post_unpack(parents=parents, data=data)
763763
if repeat:
764764
raise NotImplementedError(
765765
'cannot repeat unpack for dynamic structures')
766766
continue
767767
if isinstance(f.format, Structure):
768-
logger.debug('parsing {} bytes for {}'.format(
769-
f.format.size, f.format.format))
768+
logger.debug('parsing %s bytes for %s',
769+
f.format.size, f.format.format)
770770
bs = [stream.read(f.format.size) for i in range(f.item_count)]
771771

772772
def unpack():
@@ -785,10 +785,10 @@ def unpack():
785785
size = _struct.calcsize(field_format)
786786
except _struct.error as e:
787787
logger.error(e)
788-
logger.error('{}.{}: {}'.format(self, f, field_format))
788+
logger.error('%s.%s: %s', self, f, field_format)
789789
raise
790-
logger.debug('parsing {} bytes for preliminary {}'.format(
791-
size, field_format))
790+
logger.debug('parsing %s bytes for preliminary %s',
791+
size, field_format)
792792
raw = stream.read(size)
793793
if len(raw) < size:
794794
raise ValueError(
@@ -798,8 +798,8 @@ def unpack():
798798
def unpack():
799799
field_format = self.byte_order + f.format * f.item_count
800800
field_format = field_format.replace('P', 'I')
801-
logger.debug('parse previous bytes using {}'.format(
802-
field_format))
801+
logger.debug('parse previous bytes using %s',
802+
field_format)
803803
struct = _struct.Struct(field_format)
804804
items = struct.unpack(raw)
805805
return f.unpack_data(items)
@@ -809,12 +809,12 @@ def unpack():
809809
while repeat:
810810
d[f.name] = unpack()
811811
if hasattr(f, 'post_unpack'):
812-
logger.debug('post-unpack {}'.format(f))
812+
logger.debug('post-unpack %s', f)
813813
repeat = f.post_unpack(parents=parents, data=data)
814814
else:
815815
repeat = False
816816
if repeat:
817-
logger.debug('repeat unpack for {}'.format(f))
817+
logger.debug('repeat unpack for %s', f)
818818

819819
return data
820820

0 commit comments

Comments
 (0)