#!/usr/bin/python
# -*- coding: UTF-8 -*-

import time
import logging
import traceback

# logging.basicConfig(level=logging.INFO, filename="{}_log.txt".format(__file__[:-3]), filemode="w", format='%(asctime)s-%(filename)s[line:%(lineno)d]-%(levelname)s: %(message)s')

def init_logging(the_level=logging.INFO, the_filename="{}_log.txt".format(__file__[:-3]), the_filemode="a", the_format='%(asctime)s-%(filename)s[line:%(lineno)d]-%(levelname)s: %(message)s'):
    logging.basicConfig(level = the_level, filename= the_filename, filemode=the_filemode, format=the_format)

def record_time(fun_name):
    """記錄程序執(zhí)行時間工具"""
    def wrapper(fun):
        def inner(*fun_params):
            run_flag = False  # 標記作業(yè)是否正常執(zhí)行
            start_time = time.time()
            logging.info("程序運行時間:{}  執(zhí)行函數(shù):{} ".format(time.strftime("%Y%m%d %H:%M:%S", time.localtime(start_time)), fun_name))
            try:
                fun(*fun_params)
                run_flag = True
            finally:
                run_result = "成功" if run_flag else "失敗"
                logging.info("執(zhí)行函數(shù){}:   {}".format(fun_name, run_result) )

                # 統(tǒng)計單個作業(yè)運行時長
                end_time = time.time()
                run_time = end_time - start_time
                logging.info("開始時間:{}  結(jié)束時間:{}  耗時:{:.0f} 秒".format(time.strftime("%Y%m%d %H:%M:%S", time.localtime(start_time)),
                                                     time.strftime("%Y%m%d %H:%M:%S", time.localtime(end_time)), run_time))

        return inner
    return wrapper


@record_time("extract_data")
def test_fun():
    for i in range(5):
        logging.info("this is info message")
        time.sleep(1)
        if i == 1:
            1/0


if __name__ == '__main__':
    try:
        init_logging()
        test_fun()
    except Exception as e:
        logging.error("\033[35m  bug message:\n{}\n".format(traceback.format_exc()))