Added 'if _xd:' wrapper around expensive debug logging calls

* generating numpy lists for printing is pretty expensive when doing it thousands of time as in the unit tests
This commit is contained in:
Rob McMullen 2017-05-07 12:23:51 -07:00
parent f41f86c1b0
commit 6047824405
4 changed files with 48 additions and 32 deletions

View File

@ -7,6 +7,10 @@ from utils import *
import logging import logging
log = logging.getLogger(__name__) log = logging.getLogger(__name__)
try: # Expensive debugging
_xd = _expensive_debugging
except NameError:
_xd = False
class AtariDosWriteableSector(WriteableSector): class AtariDosWriteableSector(WriteableSector):
@ -22,7 +26,7 @@ class AtariDosWriteableSector(WriteableSector):
self.data[index + 0] = (self.file_num << 2) | (hi & 0x03) self.data[index + 0] = (self.file_num << 2) | (hi & 0x03)
self.data[index + 1] = lo self.data[index + 1] = lo
self.data[index + 2] = self.used self.data[index + 2] = self.used
log.debug("sector metadata for %d: %s" % (self._sector_num, self.data[index:index + 3])) if _xd: log.debug("sector metadata for %d: %s" % (self._sector_num, self.data[index:index + 3]))
# file number will be added later when known. # file number will be added later when known.
@ -31,10 +35,10 @@ class AtariDosVTOC(VTOC):
self.vtoc1 = segments[0].data self.vtoc1 = segments[0].data
bits = np.unpackbits(self.vtoc1[0x0a:0x64]) bits = np.unpackbits(self.vtoc1[0x0a:0x64])
self.sector_map[0:720] = bits self.sector_map[0:720] = bits
log.debug("vtoc before:\n%s" % str(self)) if _xd: log.debug("vtoc before:\n%s" % str(self))
def calc_bitmap(self): def calc_bitmap(self):
log.debug("vtoc after:\n%s" % str(self)) if _xd: log.debug("vtoc after:\n%s" % str(self))
packed = np.packbits(self.sector_map[0:720]) packed = np.packbits(self.sector_map[0:720])
self.vtoc1[0x0a:0x64] = packed self.vtoc1[0x0a:0x64] = packed
s = WriteableSector(self.sector_size, self.vtoc1) s = WriteableSector(self.sector_size, self.vtoc1)
@ -52,7 +56,7 @@ class AtariDosDirectory(Directory):
def encode_dirent(self, dirent): def encode_dirent(self, dirent):
data = dirent.encode_dirent() data = dirent.encode_dirent()
log.debug("encoded dirent: %s" % data) if _xd: log.debug("encoded dirent: %s" % data)
return data return data
def set_sector_numbers(self, image): def set_sector_numbers(self, image):
@ -225,7 +229,7 @@ class AtariDosDirent(Dirent):
self.file_num = index self.file_num = index
self.dos_2 = True self.dos_2 = True
self.in_use = True self.in_use = True
log.debug("set_values: %s" % self) if _xd: log.debug("set_values: %s" % self)
class MydosDirent(AtariDosDirent): class MydosDirent(AtariDosDirent):
@ -279,7 +283,7 @@ class AtariDosFile(object):
pos = 0 pos = 0
style_pos = 0 style_pos = 0
first = True first = True
log.debug("Initial parsing: size=%d" % self.size) if _xd: log.debug("Initial parsing: size=%d" % self.size)
while pos < self.size: while pos < self.size:
if pos + 1 < self.size: if pos + 1 < self.size:
header, = b[pos:pos+2].view(dtype='<u2') header, = b[pos:pos+2].view(dtype='<u2')
@ -294,7 +298,7 @@ class AtariDosFile(object):
continue continue
elif first: elif first:
raise InvalidBinaryFile("Object file doesn't start with 0xffff") raise InvalidBinaryFile("Object file doesn't start with 0xffff")
log.debug("header parsing: header=0x%x" % header) if _xd: log.debug("header parsing: header=0x%x" % header)
if len(b[pos:pos + 4]) < 4: if len(b[pos:pos + 4]) < 4:
self.segments.append(ObjSegment(r[pos:pos + 4], 0, 0, 0, len(b[pos:pos + 4]), "Short Segment Header")) self.segments.append(ObjSegment(r[pos:pos + 4], 0, 0, 0, len(b[pos:pos + 4]), "Short Segment Header"))
break break

View File

@ -6,6 +6,10 @@ from utils import *
import logging import logging
log = logging.getLogger(__name__) log = logging.getLogger(__name__)
try: # Expensive debugging
_xd = _expensive_debugging
except NameError:
_xd = False
class BaseHeader(object): class BaseHeader(object):
@ -348,7 +352,7 @@ class DiskImageBase(object):
def write_sector_list(self, sector_list): def write_sector_list(self, sector_list):
for sector in sector_list: for sector in sector_list:
pos, size = self.header.get_pos(sector.sector_num) pos, size = self.header.get_pos(sector.sector_num)
log.debug("writing: %s at %d" % (sector, pos)) if _xd: log.debug("writing: %s at %d" % (sector, pos))
self.bytes[pos:pos + size] = sector.data self.bytes[pos:pos + size] = sector.data
def delete_file(self, filename): def delete_file(self, filename):
@ -373,7 +377,7 @@ class DiskImageBase(object):
try: try:
vtoc = self.get_vtoc_object() vtoc = self.get_vtoc_object()
for sector_num, pos, size in vtoc.iter_free_sectors(): for sector_num, pos, size in vtoc.iter_free_sectors():
log.debug("shredding: sector %s at %d, fill value=%d" % (sector_num, pos, fill_value)) if _xd: log.debug("shredding: sector %s at %d, fill value=%d" % (sector_num, pos, fill_value))
self.bytes[pos:pos + size] = fill_value self.bytes[pos:pos + size] = fill_value
except AtrError: except AtrError:
self.rollback_transaction(state) self.rollback_transaction(state)

View File

@ -7,6 +7,10 @@ from segments import DefaultSegment, EmptySegment, ObjSegment, RawTrackSectorSeg
import logging import logging
log = logging.getLogger(__name__) log = logging.getLogger(__name__)
try: # Expensive debugging
_xd = _expensive_debugging
except NameError:
_xd = False
class Dos33TSSector(WriteableSector): class Dos33TSSector(WriteableSector):
@ -24,7 +28,7 @@ class Dos33TSSector(WriteableSector):
t, s = self.header.track_from_sector(sector.sector_num) t, s = self.header.track_from_sector(sector.sector_num)
self.data[index] = t self.data[index] = t
self.data[index + 1] = s self.data[index + 1] = s
log.debug("tslist entry #%d: %d, %d" % (index, t, s)) if _xd: log.debug("tslist entry #%d: %d, %d" % (index, t, s))
index += 2 index += 2
def get_tslist(self): def get_tslist(self):
@ -93,10 +97,10 @@ class Dos33VTOC(VTOC):
# so we need to reorder them using numpy's indexing before stuffing # so we need to reorder them using numpy's indexing before stuffing
# them into the sector map # them into the sector map
self.sector_map[0:self.max_sectors] = bits[self.vtoc_bit_reorder_index] self.sector_map[0:self.max_sectors] = bits[self.vtoc_bit_reorder_index]
log.debug("vtoc before:\n%s" % str(self)) if _xd: log.debug("vtoc before:\n%s" % str(self)) # expensive debugging call
def calc_bitmap(self): def calc_bitmap(self):
log.debug("vtoc after:\n%s" % str(self)) if _xd: log.debug("vtoc after:\n%s" % str(self)) # expensive debugging call
# reverse the process from above, so swap the order of every 16 bits, # reverse the process from above, so swap the order of every 16 bits,
# turn them into bytes, then stuff them back into the vtoc. The bit # turn them into bytes, then stuff them back into the vtoc. The bit
@ -129,7 +133,7 @@ class Dos33Directory(Directory):
def encode_dirent(self, dirent): def encode_dirent(self, dirent):
data = dirent.encode_dirent() data = dirent.encode_dirent()
log.debug("encoded dirent: %s" % data) if _xd: log.debug("encoded dirent: %s" % data)
return data return data
def set_sector_numbers(self, image): def set_sector_numbers(self, image):
@ -140,7 +144,7 @@ class Dos33Directory(Directory):
t, s = image.header.track_from_sector(next_sector) t, s = image.header.track_from_sector(next_sector)
sector.data[1] = t sector.data[1] = t
sector.data[2] = s sector.data[2] = s
log.debug("directory sector %d -> next = %d" % (sector.sector_num, next_sector)) if _xd: log.debug("directory sector %d -> next = %d" % (sector.sector_num, next_sector))
current_sector = next_sector current_sector = next_sector
@ -266,7 +270,7 @@ class Dos33Dirent(Dirent):
tslist = BaseSectorList(header) tslist = BaseSectorList(header)
for start in range(0, len(sector_list), header.ts_pairs): for start in range(0, len(sector_list), header.ts_pairs):
end = min(start + header.ts_pairs, len(sector_list)) end = min(start + header.ts_pairs, len(sector_list))
log.debug("ts: %d-%d" % (start, end)) if _xd: log.debug("ts: %d-%d" % (start, end))
s = Dos33TSSector(header, sector_list, start, end) s = Dos33TSSector(header, sector_list, start, end)
s.ts_start, s.ts_end = start, end s.ts_start, s.ts_end = start, end
tslist.append(s) tslist.append(s)
@ -274,7 +278,7 @@ class Dos33Dirent(Dirent):
vtoc.assign_sector_numbers(self, tslist) vtoc.assign_sector_numbers(self, tslist)
sector_list.extend(tslist) sector_list.extend(tslist)
self.track, self.sector = header.track_from_sector(tslist[0].sector_num) self.track, self.sector = header.track_from_sector(tslist[0].sector_num)
log.debug("track/sector lists:\n%s" % str(tslist)) if _xd: log.debug("track/sector lists:\n%s" % str(tslist))
def sanity_check(self, image): def sanity_check(self, image):
if self.deleted: if self.deleted:
@ -294,7 +298,7 @@ class Dos33Dirent(Dirent):
sector_map = [] sector_map = []
while sector_num > 0: while sector_num > 0:
image.assert_valid_sector(sector_num) image.assert_valid_sector(sector_num)
log.debug("reading track/sector list at %d for %s" % (sector_num, self)) if _xd: log.debug("reading track/sector list at %d for %s" % (sector_num, self))
data, _ = image.get_sectors(sector_num) data, _ = image.get_sectors(sector_num)
sector = Dos33TSSector(image.header, data=data) sector = Dos33TSSector(image.header, data=data)
sector.sector_num = sector_num sector.sector_num = sector_num
@ -318,7 +322,7 @@ class Dos33Dirent(Dirent):
if not self.is_sane: if not self.is_sane:
raise InvalidDirent("Invalid directory entry '%s'" % str(self)) raise InvalidDirent("Invalid directory entry '%s'" % str(self))
self.get_track_sector_list(image) self.get_track_sector_list(image)
log.debug("start_read: %s, t/s list: %s" % (str(self), str(self.sector_map))) if _xd: log.debug("start_read: %s, t/s list: %s" % (str(self), str(self.sector_map)))
self.current_sector_index = 0 self.current_sector_index = 0
self.current_read = self.num_sectors self.current_read = self.num_sectors
@ -327,7 +331,7 @@ class Dos33Dirent(Dirent):
sector = self.sector_map[self.current_sector_index] sector = self.sector_map[self.current_sector_index]
except IndexError: except IndexError:
sector = -1 # force ByteNotInFile166 error at next read sector = -1 # force ByteNotInFile166 error at next read
log.debug("read_sector: index %d=%d in %s" % (self.current_sector_index,sector, str(self))) if _xd: log.debug("read_sector: index %d=%d in %s" % (self.current_sector_index,sector, str(self)))
last = (self.current_sector_index == len(self.sector_map) - 1) last = (self.current_sector_index == len(self.sector_map) - 1)
raw, pos, size = image.get_raw_bytes(sector) raw, pos, size = image.get_raw_bytes(sector)
bytes, num_data_bytes = self.process_raw_sector(image, raw) bytes, num_data_bytes = self.process_raw_sector(image, raw)
@ -411,11 +415,11 @@ class Dos33DiskImage(DiskImageBase):
if data[1] < 35 and data[2] < 16: if data[1] < 35 and data[2] < 16:
data, style = self.get_sectors(self.header.first_vtoc + 14) data, style = self.get_sectors(self.header.first_vtoc + 14)
if data[2] != 13: if data[2] != 13:
log.warning("DOS 3.3 byte swap needed!")
swap_order = True swap_order = True
else: else:
raise InvalidDiskImage("Invalid VTOC location for DOS 3.3") raise InvalidDiskImage("Invalid VTOC location for DOS 3.3")
log.debug("DOS 3.3 byte swap: %s" % swap_order)
vtoc_type = np.dtype([ vtoc_type = np.dtype([
('unused1', 'S1'), ('unused1', 'S1'),
@ -453,7 +457,7 @@ class Dos33DiskImage(DiskImageBase):
files = [] files = []
while sector > 0: while sector > 0:
self.assert_valid_sector(sector) self.assert_valid_sector(sector)
log.debug("reading catalog sector: %d" % sector) if _xd: log.debug("reading catalog sector: %d" % sector)
values, style = self.get_sectors(sector) values, style = self.get_sectors(sector)
sector = self.header.sector_from_track(values[1], values[2]) sector = self.header.sector_from_track(values[1], values[2])
i = 0xb i = 0xb
@ -468,7 +472,7 @@ class Dos33DiskImage(DiskImageBase):
files.append(dirent) files.append(dirent)
if directory is not None: if directory is not None:
directory.set(num, dirent) directory.set(num, dirent)
log.debug("valid directory entry %s" % dirent) if _xd: log.debug("valid directory entry %s" % dirent)
i += 0x23 i += 0x23
num += 1 num += 1
self.files = files self.files = files
@ -525,7 +529,7 @@ class Dos33DiskImage(DiskImageBase):
sector = self.header.first_directory sector = self.header.first_directory
while sector > 0: while sector > 0:
self.assert_valid_sector(sector) self.assert_valid_sector(sector)
log.debug("loading directory segment from catalog sector %d" % sector) if _xd: log.debug("loading directory segment from catalog sector %d" % sector)
raw, pos, size = self.get_raw_bytes(sector) raw, pos, size = self.get_raw_bytes(sector)
byte_order.extend(range(pos, pos + size)) byte_order.extend(range(pos, pos + size))
sector = self.header.sector_from_track(raw[1], raw[2]) sector = self.header.sector_from_track(raw[1], raw[2])
@ -557,7 +561,7 @@ class Dos33DiskImage(DiskImageBase):
self.assert_valid_sector(sector_num) self.assert_valid_sector(sector_num)
raw, _, _ = self.get_raw_bytes(sector_num) raw, _, _ = self.get_raw_bytes(sector_num)
next_sector = self.header.sector_from_track(raw[1], raw[2]) next_sector = self.header.sector_from_track(raw[1], raw[2])
log.debug("checking catalog sector %d, next catalog sector: %d" % (sector_num, next_sector)) if _xd: log.debug("checking catalog sector %d, next catalog sector: %d" % (sector_num, next_sector))
if next_sector == 0: if next_sector == 0:
raise NoSpaceInDirectory("No space left in catalog") raise NoSpaceInDirectory("No space left in catalog")
return sector_num, next_sector return sector_num, next_sector
@ -596,7 +600,7 @@ class Dos33DiskImage(DiskImageBase):
for s in segments: for s in segments:
origin = min(origin, s.start_addr) origin = min(origin, s.start_addr)
last = max(last, s.start_addr + len(s)) last = max(last, s.start_addr + len(s))
log.debug("contiguous bytes needed: %04x - %04x" % (origin, last)) if _xd: log.debug("contiguous bytes needed: %04x - %04x" % (origin, last))
if run_addr and run_addr != origin: if run_addr and run_addr != origin:
# check if run_addr points to some location that has data # check if run_addr points to some location that has data
found = False found = False
@ -652,7 +656,7 @@ class Dos33BinFile(object):
pos = 0 pos = 0
style_pos = 0 style_pos = 0
first = True first = True
log.debug("Initial parsing: size=%d" % self.size) if _xd: log.debug("Initial parsing: size=%d" % self.size)
if len(b[pos:pos + 4]) == 4: if len(b[pos:pos + 4]) == 4:
start, count = b[pos:pos + 4].view(dtype='<u2') start, count = b[pos:pos + 4].view(dtype='<u2')
s[pos:pos + 4] = get_style_bits(data=True) s[pos:pos + 4] = get_style_bits(data=True)

View File

@ -6,6 +6,10 @@ from errors import *
import logging import logging
log = logging.getLogger(__name__) log = logging.getLogger(__name__)
try: # Expensive debugging
_xd = _expensive_debugging
except NameError:
_xd = False
def to_numpy(value): def to_numpy(value):
@ -176,7 +180,7 @@ class Directory(BaseSectorList):
def set(self, index, dirent): def set(self, index, dirent):
self.dirents[index] = dirent self.dirents[index] = dirent
log.debug("set dirent #%d: %s" % (index, dirent)) if _xd: log.debug("set dirent #%d: %s" % (index, dirent))
def get_free_dirent(self): def get_free_dirent(self):
used = set() used = set()
@ -240,10 +244,10 @@ class Directory(BaseSectorList):
current = 0 current = 0
for index, dirent in d: for index, dirent in d:
for missing in range(current, index): for missing in range(current, index):
log.debug("Encoding empty dirent at %d" % missing) if _xd: log.debug("Encoding empty dirent at %d" % missing)
data = self.encode_empty() data = self.encode_empty()
self.store_encoded(data) self.store_encoded(data)
log.debug("Encoding dirent: %s" % dirent) if _xd: log.debug("Encoding dirent: %s" % dirent)
data = self.encode_dirent(dirent) data = self.encode_dirent(dirent)
self.store_encoded(data) self.store_encoded(data)
current = index + 1 current = index + 1
@ -260,7 +264,7 @@ class Directory(BaseSectorList):
def store_encoded(self, data): def store_encoded(self, data):
while True: while True:
log.debug("store_encoded: %d bytes in %s" % (len(data), self.current_sector)) if _xd: log.debug("store_encoded: %d bytes in %s" % (len(data), self.current_sector))
data = self.current_sector.add_data(data) data = self.current_sector.add_data(data)
if len(data) > 0: if len(data) > 0:
self.sectors.append(self.current_sector) self.sectors.append(self.current_sector)
@ -329,7 +333,7 @@ class VTOC(BaseSectorList):
order = [] order = []
for i in range(num): for i in range(num):
order.append(self.get_next_free_sector()) order.append(self.get_next_free_sector())
log.debug("Sectors reserved: %s" % order) if _xd: log.debug("Sectors reserved: %s" % order)
self.calc_bitmap() self.calc_bitmap()
return order return order
@ -337,7 +341,7 @@ class VTOC(BaseSectorList):
free = np.nonzero(self.sector_map)[0] free = np.nonzero(self.sector_map)[0]
if len(free) > 0: if len(free) > 0:
num = free[0] num = free[0]
log.debug("Found sector %d free" % num) if _xd: log.debug("Found sector %d free" % num)
self.sector_map[num] = 0 self.sector_map[num] = 0
return num return num
raise NotEnoughSpaceOnDisk("No space left in VTOC") raise NotEnoughSpaceOnDisk("No space left in VTOC")