def voltageRamp(self, volt_ramp, ts_start=None): """Perform voltage ramp volt_ramp - dict with keys: volt_start, volt_end, volt_step, time_step ts_start - start time (now() if None)""" tid = syscall(SYS_gettid) self.logger.debug('voltageRamp: name %s, tid %d', threading.current_thread().name, tid) assert self.uubch is not None, "Channel for voltage ramp not provided" ch = self.uubch if any([ key not in volt_ramp for key in ('nstep', 'ts_start', 'ts_end', 'tdelta') ]): self._voltRamp_validate(volt_ramp, ts_start) MSG = 'voltage ramp [{volt_start:.1f}:{volt_step:.1f}:' + \ '{volt_end:.1f}] V, duration {duration:.1f}s' self.logger.info(MSG.format(**volt_ramp)) volt = volt_ramp['volt_start'] timestamp = volt_ramp['ts_start'] self.setVoltage(ch, volt) for _ in range(volt_ramp['nstep']): volt += volt_ramp['volt_step'] timestamp += volt_ramp['tdelta'] sec = (timestamp - datetime.now()).total_seconds() if sec > 0.0: sleep(sec) self.setVoltage(ch, volt)
def run(self): assert multiprocessing.get_start_method() == 'forkserver', \ """Multiprocessing start method must be 'forkserver' call multiprocessing.set_start_method("forkserver") before Backup.start()""" tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) for datadir in self.datadirs: if self.stop: self.logger.info('Stop required') break self.p_recv, self.p_send = multiprocessing.Pipe(False) self.ns.datadir = datadir assert self.ns.filled(), \ "Incomplete NameSpace: " + self.ns.__str__() self.logger.info('Backing up %s', datadir) # create all intermediate directories if necessary parts = datadir.rsplit(sep=os.sep, maxsplit=1) if len(parts) == 2: os.makedirs(os.path.join(self.ns.destdir, parts[0]), exist_ok=True) # run compressor and shafiles processes self.procs = [multiprocessing.Process( target=compressor, name='compressor', args=( self.ns, self.p_recv, self.q_asha))] self.procs.extend([multiprocessing.Process( target=shafiles, name='shafile_%d' % i, args=( self.ns, self.q_files, self.q_fsha)) for i in range(self.n_shaproc)]) for p in self.procs: p.start() self.logger.debug('Starting process: %s, pid %d', p.name, p.pid) self.p_recv.close() self.ns.data_fd # trigger openning of datadir fd # run ShareTar thread self.st = ShareTar( self.ns, self.n_shaproc, self.n_fr, self.p_send, self.q_fn, self.q_files, self.mmaps) self.st.start() self.cs = CollectSha(self.ns, self.mmaps, self.q_asha, self.q_fsha, self.evt_done) self.cs.start() # wait for finish and clean up self.logger.debug('threads/processes started, waiting for done') self.evt_done.wait() self.logger.debug('done, joining threads/processes') self.st.join() for p in self.procs: p.join() self.cs.join() del self.ns.data_fd # close datadir fd for q in self.q_fn, self.q_files, self.q_fsha, self.q_asha: assert q.empty(), 'Remains in %s' % q assert self.mmaps == {}, \ 'Remaining mmaps: %s' % ', '.join(self.mmaps.keys()) self.evt_alldone.set()
def orderUUB(self, abort=True, timestamp=None): """Find order of UUBs connected to powercontrol. Suppose all UUBs are booted, switch them one by one to determine their order Return their order Raise AssertionError in a non-allowed situation""" tid = syscall(SYS_gettid) self.logger.debug('Checkin UUB order, name %s, tid %d', threading.current_thread().name, tid) uubset_all = {uubnum for uubnum in self.uubnums if uubnum is not None} maxind = max( [i for i, uubnum in enumerate(self.uubnums) if uubnum is not None]) uub2ip = {uubnum: uubnum2ip(uubnum) for uubnum in uubset_all} uubset_exp = { uubnum for uubnum in uubset_all if isLive(uub2ip[uubnum], self.logger) } uubnums = [] # tested order of UUBs portmask = 1 # raw ports to switch off for n in range(9, -1, -1): # expected max number of live UUBs self.pc.switchRaw(False, portmask) portmask <<= 1 sleep(Evaluator.TOUT_ORD) uubset_real = { uubnum for uubnum in uubset_all if isLive(uub2ip[uubnum], self.logger) } self.logger.debug( 'n = %d, UUBs still live = %s', n, ', '.join(['%04d' % uubnum for uubnum in uubset_real])) assert (len(uubset_real) <= n), 'Too much UUBs still live' assert (uubset_real <= uubset_exp), 'UUB reincarnation?' diflist = list(uubset_exp - uubset_real) assert len(diflist) <= 1, 'More than 1 UUB died' uubnums.append(diflist[0] if diflist else None) uubset_exp = uubset_real maxind = max( [maxind] + [i for i, uubnum in enumerate(self.uubnums) if uubnum is not None]) zFail = uubnums[:maxind + 1] != self.uubnums[:maxind + 1] if zFail: uubs = [ '%04d' % uubnum if uubnum else 'null' for uubnum in uubnums ] msglines = [ 'Incorrect UUB numbers.', 'Detected UUBs: [ %s ].' % ', '.join(uubs) ] if abort: msglines.append('Aborting.') self.writeMsg(msglines, timestamp) self.logger.info(' '.join(msglines)) if abort and zFail: self.critical_error() return uubnums
def run(self): tid = syscall(SYS_gettid) self.logger.info('Starting QueDispatch, name %s, tid %d', threading.current_thread().name, tid) while True: item = self.q_in.get() if item is None: break if self.zLog: self.logger.debug(repr(item)) self.q_out.put(item) self.logger.info('QueDispatch Finished')
def run(self): logger = logging.getLogger('QueView') tid = syscall(SYS_gettid) logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) while True: if self.timer.stop.is_set(): logger.info('Timer stopped, stopping QueView') return try: item = self.q.get(True, self.timeout) except Empty: continue logger.debug(repr(item))
def readZone(self): """Function running in a separate thread to read current zone transitions periodically""" tid = syscall(SYS_gettid) self.logger.debug('readZone: name %s, tid %d', threading.current_thread().name, tid) tout = self.rz_tout while tout: self.curzones.extend(self._readZones()) self.rz_done.set() if self.rz_wake.wait(tout): self.rz_wake.clear() tout = self.rz_tout self.logger.debug('readZone finished')
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) while True: self.timer.evt.wait() if self.timer.stop.is_set(): break timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags # join old volt_ramp threads if self.vramps: vramps = [] # new list for unfinished ramps for ts, thr in self.vramps: if ts is None or ts < timestamp: thr.join(0.001) if thr.is_alive(): self.logger.warning('Join %s timeouted', thr.name) vramps.append((None, thr)) else: vramps.append((ts, thr)) self.vramps = vramps if 'power' in flags: # interpret uubch, ch%d self.config(**flags['power']) if 'meas.sc' in flags and self.q_resp is not None: voltage, current = self.readVoltCurr() rec = {'timestamp': timestamp, 'meas_sc': True} if voltage is not None: rec['ps_u'] = voltage if current is not None: rec['ps_i'] = current self.q_resp.put(rec) if 'power' in flags and 'volt_ramp' in flags['power']: live_vr = [thr for ts, thr in self.vramps if ts is not None] if live_vr: self.logger.error('Still running voltage ramps: %s', ', '.join([thr.name for thr in live_vr])) volt_ramp = self._voltRamp_validate( flags['power']['volt_ramp'], ts_start=timestamp) thr = threading.Thread(target=self.voltageRamp, args=(volt_ramp, )) self.vramps.append((volt_ramp['ts_end'], thr)) thr.start() self.logger.info('run finished')
def run(self): logger = logging.getLogger('ESSprogram') tid = syscall(SYS_gettid) logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) if self.load: self.timer.add_immediate('binder.load_prog', { 'prog': self.prog, 'progno': self.progno }) timestamp = None ltime, lto = self.lto_touts.pop(0) while True: self.timer.evt.wait() if self.timer.stop.is_set(): logger.info('Timer stopped, stopping ESSprogram') return if timestamp == self.timer.timestamp: continue # already processed timestamp timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags if self.starttime is None or self.stoptime < timestamp: dur = None else: dur = int((timestamp - self.starttime).total_seconds() + 0.5) if dur < 0: dur = None res = {'timestamp': timestamp, 'rel_time': dur} if ltime is not None and dur is not None and ltime <= dur: if ltime == dur: res['log_timeout'] = lto ltime, lto = self.lto_touts.pop(0) for name in ('meas.ramp', 'meas.noise', 'meas.pulse', 'meas.freq'): if name in flags: mname = name.split('.')[1] res['meas_' + mname] = True if 'db' in flags[name]: res['db_' + mname] = flags[name]['db'] # modify db_noise -> db_noisestat if count in flags[meas.noise] if 'meas.noise' in flags and 'count' in flags['meas.noise'] and \ 'db_noise' in res: res['db_noisestat'] = res.pop('db_noise') if dur in self.timepoints: res['meas_point'] = self.timepoints[dur] res['events'] = ' '.join(flags.keys()) if self.time_temp and dur is not None: res['set_temp'] = self.polyline(dur, self.time_temp) if self.time_humid and dur is not None: res['set_humid'] = self.polyline(dur, self.time_humid) self.q_resp.put(res)
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) while True: self.timer.evt.wait() if self.timer.stop.is_set(): self.logger.info('Evaluator stopped') return timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags # join removeUUB threads if self.thrs: thrs = [] # new list for unjoined threads for thr in self.thrs: thr.join(0.001) if thr.is_alive(): self.logger.warning('Join %s timeouted', thr.name) thrs.append(thr) self.thrs = thrs if 'eval' in flags: flags = flags['eval'] else: continue if 'checkISN' in flags: self.checkISN(flags['checkISN'], timestamp) if 'orderUUB' in flags: thr = threading.Thread(target=self.orderUUB, name='Thread-orderUUB', args=(flags['orderUUB'], timestamp)) self.thrs.append(thr) thr.start() if 'removeUUB' in flags: for uubnum in flags['removeUUB']: thr = threading.Thread(target=self.removeUUB, name='Thread-removeUUB', args=(uubnum, self.logger)) thr.start() self.thrs.append(thr) if 'message' in flags: msglines = flags['message'].splitlines() self.writeMsg(msglines, timestamp)
def run(self): logger = logging.getLogger('EvtDisp') tid = syscall(SYS_gettid) logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) timestamp = None while True: self.timer.evt.wait() if self.timer.stop.is_set(): logger.info('Timer stopped, stopping EvtDisp') return if timestamp == self.timer.timestamp: continue # already processed timestamp timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags logger.debug('timestamp: %s, flags: %s', timestamp.strftime('%Y-%m-%dT%H:%M:%S'), repr(flags))
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) while True: self.timer.evt.wait() if self.timer.stop.is_set(): self.logger.info('Timer stopped, closing serial') self.binder.modbus.ser.close() self.binder = None return timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags if 'binder.start_prog' in flags: try: progno = int(flags['binder.start_prog']) self.logger.info('Starting program %d', progno) self.binder.start_prog(progno) except Exception as e: self.logger.error('Error starting chamber program. %s', e) if 'binder.stop_prog' in flags: manual = flags['binder.stop_prog'] self.binder.stop_prog(manual) if 'meas.thp' in flags: self.logger.debug('Chamber temperature & humidity measurement') res = {'timestamp': timestamp, 'meas_thp': True} try: res['temperature'] = temperature = self.binder.get_temp() except ModbusError: temperature = float('nan') self.logger.error('Error reading chamber temperature') try: res['humid'] = humid = self.binder.get_humid() except ModbusError: humid = float('nan') self.logger.error('Error reading chamber humidity') if 'temperature' in res or 'humid' in res: self.logger.debug('Done. t = %.2fdeg.C, h = %.2f%%' % (temperature, humid)) self.q_resp.put(res) if 'binder.load_prog' in flags: progno, prog = (flags['binder.load_prog']['progno'], flags['binder.load_prog']['prog']) self.logger.info('Loading program %d', progno) self.binder.load_prog(progno, prog)
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) compress_done = False queues = [self.q_asha._reader.fileno(), self.q_fsha._reader.fileno()] while not compress_done or self.mmaps: rd_ready, o, e = select.select(queues, [], []) if queues[0] in rd_ready: asha = self.q_asha.get() compress_done = True self.logger.debug('Received archive SHA') if queues[1] in rd_ready: fn, fsha = self.q_fsha.get() self.fshas.append((fn, fsha)) mm = self.mmaps.pop(fn, None) if mm is not None: mm.close() self.logger.debug('Compress done and all mmaps released') fshas = sorted(self.fshas) fn_sha = self.ns.templ_sha1sum.format(datadir=self.ns.datadir) fp = open(os.path.join(self.ns.destdir, fn_sha), 'wb') h = hashlib.sha1() offset, size, nlines = 0, len(fshas), self.NLINES while offset < size: chunk = ''.join([ '%s %s\n' % (fsha.hex(), os.path.join(self.ns.datadir, fn)) for (fn, fsha) in fshas[offset:offset+nlines]]) chunk = bytes(chunk, 'utf-8') fp.write(chunk) h.update(chunk) offset += nlines fp.close() os.chmod(os.path.join(self.ns.destdir, fn_sha), stat.S_IRUSR | stat.S_IRGRP | stat.S_IROTH) ssha = h.digest() fn_lz4 = self.ns.templ_lz4.format(datadir=self.ns.datadir) with open(os.path.join(self.ns.destdir, self.ns.fn_sha1sums), 'a') as fp: fp.write('%s %s\n' % (asha.hex(), fn_lz4)) fp.write('%s %s\n' % (ssha.hex(), fn_sha)) self.evt_done.set() self.logger.debug('run finished')
def removeUUB(self, uubnum, logger=None): """Remove UUB from running system, might run in a separate thread""" if logger is not None: tid = syscall(SYS_gettid) logger.debug('Removing UUB #%04d, name %s, tid %d', uubnum, threading.current_thread().name, tid) ind = self.uubnums.index(uubnum) self.uubnums[ind] = None if self.pc is not None: self.pc.uubnums2del.append(uubnum) self.udaq.uubnums2del.append(uubnum) self.telnet.uubnums2del.append(uubnum) self.dl.uubnums2del.append(uubnum) uub = self.uubtsc.pop(uubnum) uub.stopme = True if logger is not None: logger.debug('Joining UUBtsc #%04d', uubnum) uub.join() if logger is not None: logger.debug('UUB #%04d removed', uubnum)
def _fastadc(self, port): """Function running in a separate thread to actually start fast ADC acquisition, read and store data to fastadc_data blocks. Acquisition is stopped by fastADC_stop() function writing 'A' to the power control device""" tid = syscall(SYS_gettid) logger = logging.getLogger('fastADC') logger.debug('thread started: name %s, tid %d', threading.current_thread().name, tid) self.fastadc_block = mmap.mmap(-1, self.FASIZE) with self._lock: self.ser.write(b'a%d\r' % port) state = PowerControl.FADCstate() resp = readSerRE(self.ser, PowerControl.re_fastadc_st, buf=state.buf, timeout=0.5) m = PowerControl.re_fastadc_st.match(resp) d = m.groupdict() if port != int(d['port']): logger.error('port mismatch: set %d, recieved %d', port, int(d['port'])) return self.fastadc_conv = [ np.float32(d[key]) for key in ('offset', 'slope') ] state.fp = open('/tmp/fastadc', 'wb') while state.running: inwait = self.ser.inWaiting() if inwait > 0: state.buf += self.ser.read(inwait) self._fastadc_procbuf(state) sleep(0.001) self.fastadc_data.append(self.fastadc_block) self.fastadc_block = None resp = readSerRE(self.ser, PowerControl.re_fastadc_en, buf=state.buf, logger=logger, timeout=0.01) logger.info('thread finished')
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) self.tf = tarfile.open(mode='w|', fileobj=self.fo, bufsize=TARBUFSIZE, format=TARFORMAT) self.tf.add(self.srcdir, arcname=self.ns.datadir, recursive=False) self.fcount = 1 # run FileReader threads self.frs = [FileReader(self, i) for i in range(self.n_fr)] for fr in self.frs: fr.start() # logging progress t0 = datetime.now() t1 = t0 + timedelta(seconds=TDELTA) lastf, lastb = 0, 0 for fn in self.iterFiles(): if datetime.now() > t1: speedf = (self.fcount - lastf) / TDELTA speedMiB = (self.fo.bcount - lastb) / TDELTA / 1024 / 1024 lastf, lastb = self.fcount, self.fo.bcount self.logger.debug('Processed %6d files, %7.1f MiB, ' + 'speed %5.1f files/s, %5.1f MiB/s', self.fcount, self.fo.bcount / 1024 / 1024, speedf, speedMiB) t1 += timedelta(seconds=TDELTA) self.q_fn.put(fn) # wait for FileReader threads to finish for _ in range(self.n_fr): self.q_fn.put(None) for fr in self.frs: fr.join() self.tf.close() for _ in range(self.n_shaproc): self.q_files.put((None, None)) # sentinels self.logger.info('Processed %d files, %.1f MiB in %.1fs', self.fcount, self.fo.bcount / 1024/1024, (datetime.now() - t0).total_seconds()) self.fo.close()
def run(self): if self.timer is None or self.q_resp is None: self.logger.error('timer or q_resp instance not provided, exiting') return tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) while True: self.timer.evt.wait() if self.timer.stop.is_set(): self.logger.info('Timer stopped') break timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags if 'meas.thp' not in flags: continue res = self.measure() if res: res['timestamp'] = timestamp res['meas_thp'] = True self.q_resp.put(res) self.logger.info('Run finished')
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) data_fd = self.st.ns.data_fd # caching while True: self.privlog('---\nq_fn.get') fn = self.st.q_fn.get() if fn is None: break self.privlog('os.open') fd = os.open(fn, os.O_RDONLY, dir_fd=data_fd) self.privlog('os.stat') filestat = os.stat(fd) if filestat.st_size > 0: self.privlog('mmap') mm = mmap.mmap(fd, 0, flags=mmap.MAP_SHARED, prot=mmap.PROT_READ) self.st.mmaps[fn] = mm self.privlog('io.Bytes') bufdata = io.BytesIO(mm.read()) self.privlog('bytes read') else: self.privlog('empty file') bufdata = io.BytesIO(b'') os.close(fd) tarfn = os.path.join(self.st.ns.datadir, fn) ti = makeTarInfo(filestat, tarfn) or \ self.st.tf.gettarinfo(os.path.join(self.srcdir, fn), tarfn) with self.st._lock: self.privlog('addfile') self.st.fcount += 1 self.st.tf.addfile(ti, bufdata) self.privlog('bufdata.close') bufdata.close() self.privlog('q_files.put') self.st.q_files.put((fn, filestat.st_size)) self.logger.debug('run() finished')
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) zTimerStop = False while not self.stop.is_set(): self.awake_coarse.clear() # update self.tickers while self.tickers2add: name, gener, offset = self.tickers2add.pop() if name in self.tickers: self.logger.error("Duplicate ticker %s, ignoring", name) continue self.logger.info('Added ticker ' + name) # at least one value must be produced nextval, detail = next(gener) nextval += offset self.tickers[name] = [nextval, detail, gener, offset] while self.tickers2del: name = self.tickers2del.pop() if name in self.tickers: del self.tickers[name] self.logger.info('Removing ticker ' + name) else: self.logger.error( 'Ticker %s not present for removal', name) if not self.tickers and not self.immediate: sleep(0.3) continue # the closest possible delta-time for event delta0 = int((datetime.now() - self.basetime).total_seconds() + Timer.EPS + 0.999999) # find minimal next values of time delta delta = min([t[0] for t in self.tickers.values()]) timestamp = self.basetime + timedelta(seconds=delta) if delta < delta0: newflags = self._getFlags(delta) self.logger.debug( 'Skipping passed tick %s, event %s', datetime.strftime(timestamp, "%Y-%m-%d %H:%M:%S"), ', '.join(newflags)) if 'stop' in newflags: self._stopTick() continue if self.immediate: delta = delta0 timestamp = self.basetime + timedelta(seconds=delta) # coarse sleep sec = (timestamp - datetime.now()).total_seconds() sec -= Timer.COARSESLEEP if sec > 0.0: self.logger.debug('coarse sleep %.3fs', sec) if self.awake_coarse.wait(sec): self.logger.info('coarse sleep interrupted, reprocessing') continue # coarse sleep was interrupted -> reprocess newflags = self._getFlags(delta) nimmediate = [] while self.immediate: name, detail = self.immediate.pop(0) if name in newflags: nimmediate.append((name, detail)) else: newflags[name] = detail self.immediate.extend(nimmediate) if 'stop' in newflags: zTimerStop = True del newflags['stop'] # fine sleep sec = (timestamp - datetime.now()).total_seconds() if sec > 0.0: self.logger.debug('fine sleep %.6fs', sec) sleep(sec) else: self.logger.error('negative fine sleep: %.6fs', -sec) if newflags: # may be empty if only stop was present self.logger.debug('event: %s', ', '.join(newflags)) timerflag = newflags.pop('timer', None) self.timestamp = timestamp self.flags = newflags self.evt.set() self.evt.clear() if timerflag is not None: for rec in timerflag['recs']: self.replace_ticker(rec) # self stop if zTimerStop: self._stopTick() zTimerStop = False self.logger.info('timer.run finished')
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) downloaded = [] while True: self.timer.evt.wait() if self.timer.stop.is_set(): self.logger.info('Timer stopped, ending run()') return timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags.get('flir', None) # flags = { <one or more actions:> # snapshot: True/False # download: True/False # delete: True/False # <parameters relevant to actions:> # * snapshot # imagename: <str>, mandatory # - internal name, unique during FLIR instance life # db: raw|eval|both # - store raw/eval image into DB, default None # rawname: <str>, conditional if db = raw or both # - attachment name for raw image # evalname: <str>, mandatory if db = eval or both # - attachment name for evaluation image # - implies evaluation # evaltitle: <str>, optional # - eval. image title template for format # - keys: uubnum, res, timestamp # evalimname: <str>, optional # - eval. image name # bgimage: True/False # - use as background for evaluation # - contradicts evalname # description: <str>, optional # - description for raw/eval image to DB # * download, delete # imagename: <str>, optional # - if present limit operation only to imagename flags, rec = self._checkFlags(flags) if flags is None: continue imagename = flags['imagename'] if flags['snapshot']: self.snapshot(imagename) self.logger.info('Image %s stored', imagename) rec['timestamp'] = timestamp self.snapshots[imagename] = rec if flags['download']: if imagename is not None: if imagename in self.snapshots: imagelist = (imagename, ) else: self.logger.error('image <%s> not stored', imagename) imagelist = [] else: imagelist = list(self.snapshots.keys()) for image in imagelist: fname = image + self.typ[1] self.getfile('images/' + fname, self.datadir + fname) downloaded.append(image) rec = self.snapshots.pop(image) arec = {'uubs': (self.uubnum, ), 'run': True} if 'description' in rec: arec['description'] = rec['description'] if rec['db'] in ('raw', 'both'): arec['name'] = rec['rawname'] arec['filename'] = self.datadir + fname, self.q_att.put(arec) if rec['bgimage']: self.fe.readFFF(self.datadir + fname, True) elif rec['evalname'] is not None: res, efname = self._evalFFF( self.datadir + fname, timestamp, rec.get('evalimname', None), rec.get('evaltitle', None)) if self.evaluator is not None: self.evaluator.writeMsg( ('FLIR evaluation: ' + FLIR.FLIR_RES[res], )) label = item2label(typ='flireval', uubnum=self.uubnum) self.q_resp.put({ 'timestamp': rec['timestamp'], 'meas_flir': True, label: res }) if rec['db'] in ('eval', 'both') and efname: arec['name'] = rec['evalname'] arec['filename'] = efname self.q_att.put(arec) if efname is not None: im = PIL.Image.open(efname) im.show() if flags['delete']: if imagename is not None: if imagename in self.snapshots: self.logger.warning( 'image %s to be deleted not downloaded', imagename) imagelist = (imagename, ) elif imagename not in downloaded: self.logger.error('image <%s> not stored', imagename) imagelist = [] else: imagelist = (imagename, ) else: imagelist, downloaded = downloaded, [] for image in imagelist: self.logger.info('Deleting image %s', image) self.deleteimage(image)
def run(self): if self.timer is None or self.q_resp is None: self.logger.error('timer or q_resp instance not provided, exiting') return tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) self.rz_thread = threading.Thread(target=self.readZone, name='Thread-readZone') self.rz_thread.start() while True: self.timer.evt.wait() if self.timer.stop.is_set(): break timestamp = self.timer.timestamp # store info from timer flags = self.timer.flags while self.uubnums2del: self._removeUUB(self.uubnums2del.pop()) if 'meas.sc' in flags: currents = self._readCurrents() res = { item2label(typ='itot', uubnum=uubnum): currents[port] for uubnum, port in self.uubnums.items() } res['timestamp'] = timestamp res['meas_sc'] = True self.q_resp.put(res) if 'power' in flags: if 'rz_tout' in flags['power']: tout = flags['power']['rz_tout'] if tout is None: self.logger.debug( 'set power.rz_tout to default value %.1fs', self.RZ_TOUT) self.rz_tout = self.RZ_TOUT else: self.logger.debug('set power.rz_tout %.1fs', tout) self.rz_tout = tout self.rz_wake.set() if flags['power'].get('pczero', False): self.zeroTime() if flags['power'].get('pccalib', False): self.calibrateTime() # valid uubs for pcon/pcoff: <list>, True, None if 'pcoff' in flags['power']: self.switch(False, flags['power']['pcoff']) if 'pcon' in flags['power']: uubs = flags['power']['pcon'] del self.curzones[:] self.switch(True, uubs) if 'check' in flags['power']: if self.boottime or self.bootvolt: self.logger.warning('pcon: already under check') self.bootvolt = None self.boottime = True self.chk_ts = timestamp if 'volt_ramp' in flags['power']: if self.boottime or self.bootvolt: self.logger.warning('voltramp: already under check') del self.curzones[:] bv = flags['power']['volt_ramp'] bv['up'] = bv['volt_start'] < bv['volt_end'] self.bootvolt = bv self.boottime = self.bootvolt['start'] self.chk_ts = timestamp if 'power.pccheck' in flags: if not self.bootvolt and not self.boottime: self.logger.error('not after pcon or volt_ramp') continue # trigger readZone and wait for done self.rz_done.clear() self.rz_wake.set() if not self.rz_done.wait(1.0): self.logger.warning('Timeout on readZone done') res = {'timestamp': self.chk_ts} if self.bootvolt: direction = 'up' if self.bootvolt['up'] else 'down' state = 'on' if self.bootvolt['start'] else 'off' res['volt_ramp'] = (direction, state) typ = 'voltramp' + direction + state for uubnum in self.uubnums: label = item2label(typ=typ, uubnum=uubnum) try: res[label] = self._voltres(uubnum) except IndexError: self.logger.warning('voltage for %s not available', label) self.bootvolt = None if self.boottime: res['boottimes'] = True for uubnum in self.uubnums: try: t1, t2 = self._boottime(uubnum) except IndexError: self.logger.warning( 'boottime for %04d not available', uubnum) continue res[item2label(typ='boottime', uubnum=uubnum)] = t1 res[item2label(typ='adcinittime', uubnum=uubnum)] = (t2 - t1) self.boottime = None self.q_resp.put(res) self.logger.info('run finished')
def run(self): tid = syscall(SYS_gettid) self.logger.debug('run start, name %s, tid %d', threading.current_thread().name, tid) last_ts = datetime(2016, 1, 1) # minus infinity self.logger.info('starting run()') while not self.stop.is_set() or self.records: while self.uubnums2del: uubnum = self.uubnums2del.pop() nhandlers = [] for rec in self.handlers: if rec[2] == uubnum: # remove uub rec[0].stop() # stop the handler else: nhandlers.append(rec) self.handlers = nhandlers # remove unused filters nfilterkeys = set( [chain for rec in self.handlers for chain in rec[1]]) self.filters = [ rec for rec in self.filters if rec[0] in nfilterkeys ] if self.records: qtend = min([rec['tend'] for rec in self.records.values()]) else: qtend = datetime.now() + timedelta(seconds=self.timeout) # logger.debug('tend = %s' % # datetime.strftime(tend, "%Y-%m-%d %H:%M:%S")) # read from queue until some record is timeouted while True: timeout = (qtend - datetime.now()).total_seconds() # logger.debug('timeout = %.6f' % timeout) if timeout < 0.0: break try: newrec = self.q_resp.get(True, timeout) except Empty: # logger.debug('q_resp.get() timeout') continue try: ts = newrec.pop('timestamp') except AttributeError: self.logger.debug('Wrong record: %s', repr(newrec)) continue if 'log_timeout' in newrec: tout = max(int(newrec.pop('log_timeout')), self.timeout) else: tout = self.timeout recalc = tout > self.timeout tend = ts + timedelta(seconds=tout) if ts in self.records: if tend > self.records[ts]['tend']: newrec['tend'] = tend else: recalc = False self.records[ts].update(newrec) elif ts > last_ts: # add only ts after the last written tend_curr = max( # latest tend of previous recs [ rec['tend'] for ts1, rec in self.records.items() if ts1 < ts ] + [ts]) if tend <= tend_curr: newrec['tend'] = tend_curr recalc = False else: newrec['tend'] = tend self.logger.debug( 'Added new record %s', datetime.strftime(ts, "%Y-%m-%d %H:%M:%S")) self.records[ts] = newrec else: self.logger.info( 'Discarding an old record %s', datetime.strftime(ts, "%Y-%m-%d %H:%M:%S")) continue # eventually increase tend for newer records if recalc: for ts1, rec in self.records.items(): if ts < ts1 and rec['tend'] < tend: rec['tend'] = tend # process expired records tnow = datetime.now() expts = [ ts for ts, rec in self.records.items() if rec['tend'] <= tnow ] for ts in sorted(expts): self.logger.debug('write rec for ts = %s', datetime.strftime(ts, "%Y-%m-%d %H:%M:%S")) if ts > last_ts: last_ts = ts rec = self.records.pop(ts) rec.pop('tend') rec['timestamp'] = ts # apply filters to rec recs = {None: rec} for key, start, filterlist in self.filters: nrec = recs[start] for filt, filtlabel in filterlist: try: nrec = filt(nrec) except Exception: msg = 'filter %s raised exception' % filtlabel if self.elogger is not None: enum = self.elogger.log(filtlabel=filtlabel, nrec=nrec) msg += ' %04d' % enum self.logger.error(msg) break recs[key] = nrec mergedrecs = {} keyslist = [rec[1] for rec in self.handlers] for keys in keyslist: if keys in mergedrecs: continue mrec = {} for key in keys: try: mrec.update(recs[key]) except Exception: self.elogger.log(mrec=mrec, key=key, recs=recs) mergedrecs[keys] = mrec # logger.debug('Rec written to handlers: %s', repr(recs)) for h, keys, uubnum in self.handlers: try: h.write_rec(mergedrecs[keys]) except Exception: msg = '%s.write_rec raised exception' % h.label if self.elogger is not None: enum = self.elogger.log(h_label=h.label, mrec=mergedrecs[keys]) msg += ' %04d' % enum self.logger.error(msg) self.logger.info('run() finished, deleting handlers') for h, keys, uubnum in self.handlers: h.stop() self.handlers = None