def _do_get_order_list(
args: TbServiceGetOrderDetailsArgs, logger: BoundLogger
) -> Optional[List[dict]]:
dtk = DtkSyncApi(SConfig.DTKAppKey, SConfig.DTKAppSecret)
ret_list = dtk.tb_service_get_order_details(args)
logger.bind(ret_list=ret_list).info("get data")
return ret_list
def to_data(self: "GaoYongForm",
logger: BoundLogger) -> Awaitable[Optional[GaoYongArgs]]:
logic = UserV2Logic(logger)
user = async_to_sync(logic.get_user_by_token(self.token))
if user is None:
logger.bind(token=self.token).error("user token is invalid")
# noinspection PyTypeChecker
return None
pid = SConfig.AliPid
sid = SConfig.ZTKSid
args = GaoYongArgs(num_iid=self.item_id, pid=pid, sid=sid)
try:
info = TBChannelIdModel.objects.get(user=user)
if info.relation_id is not None:
args.relation_id = info.relation_id
if info.special_id is not None:
args.special_id = info.special_id
# noinspection PyTypeChecker
return args
except ObjectDoesNotExist:
logger.bind(user=user).error("user not bind taobao")
# noinspection PyTypeChecker
return args
def create_session(config: Config, logger: BoundLogger) -> Session:
"""Create a new database session.
Checks that the database is available and retries in a loop for 10s if it
is not.
Parameters
----------
config : `gafaelfawr.config.Config`
The Gafaelfawr configuration.
Returns
-------
session : `sqlalchemy.orm.Session`
The database session.
"""
for _ in range(5):
try:
engine = create_engine(config.database_url)
session = Session(bind=engine)
session.execute(select(SQLAdmin))
return session
except OperationalError:
logger.info("database not ready, waiting two seconds")
time.sleep(2)
continue
# If we got here, we failed five times. Try one last time without
# catching exceptions so that we raise the appropriate exception to our
# caller.
engine = create_engine(config.database_url)
session = Session(bind=engine)
session.execute(select(Admin))
return session
def test_proxies_log(self):
"""
BoundLogger.exception.log() is proxied to the apropriate method.
"""
bl = BoundLogger(ReturnLogger(), [return_method_name], {})
assert "critical" == bl.log(50, "event")
assert "debug" == bl.log(10, "event")
def test_proxies_log(self):
"""
BoundLogger.exception.log() is proxied to the apropriate method.
"""
bl = BoundLogger(ReturnLogger(), [return_method_name], {})
assert "critical" == bl.log(50, "event")
assert "debug" == bl.log(10, "event")
def test_exception_exc_info(self):
"""
BoundLogger.exception sets exc_info=True.
"""
bl = BoundLogger(ReturnLogger(), [], {})
assert ((),
{"exc_info": True, "event": "event"}) == bl.exception('event')
async def check_database(url: str, logger: BoundLogger) -> None:
"""Check that the database is accessible.
Parameters
----------
config : `gafaelfawr.config.Config`
The Gafaelfawr configuration.
logger : `structlog.stdlib.BoundLogger`
Logger used to report problems
"""
engine = create_async_engine(url, future=True)
factory = _create_session_factory(engine)
for _ in range(5):
try:
async with factory() as session:
async with session.begin():
await session.execute(select(SQLAdmin).limit(1))
return
except (ConnectionRefusedError, OperationalError):
logger.info("database not ready, waiting two seconds")
time.sleep(2)
continue
# If we got here, we failed five times. Try one last time without
# catching exceptions so that we raise the appropriate exception to our
# caller.
async with factory() as session:
async with session.begin():
await session.execute(select(SQLAdmin).limit(1))
def test_exception_exc_info(self):
"""
BoundLogger.exception sets exc_info=True.
"""
bl = BoundLogger(ReturnLogger(), [], {})
assert ((),
{"exc_info": True, "event": "event"}) == bl.exception('event')
def test_proxies_exception(self):
"""
BoundLogger.exception is proxied to Logger.error.
"""
bl = BoundLogger(ReturnLogger(), [return_method_name], {})
assert "error" == bl.exception("event")
def only_common_columns(df: pd.DataFrame, log: stdlib.BoundLogger) -> pd.DataFrame:
"""Return a DataFrame with columns not in CommonFields dropped."""
extra_columns = {col for col in df.columns if CommonFields.get(col) is None}
if extra_columns:
log.warning("Dropping columns not in CommonFields", extra_columns=extra_columns)
df = df.drop(columns=extra_columns)
return df
def test_positional_args_proxied(self):
"""
Positional arguments supplied are proxied as kwarg.
"""
bl = BoundLogger(ReturnLogger(), [], {})
args, kwargs = bl.debug('event', 'foo', bar='baz')
assert 'baz' == kwargs.get('bar')
assert ('foo',) == kwargs.get('positional_args')
def test_positional_args_proxied(self):
"""
Positional arguments supplied are proxied as kwarg.
"""
bl = BoundLogger(ReturnLogger(), [], {})
args, kwargs = bl.debug('event', 'foo', bar='baz')
assert 'baz' == kwargs.get('bar')
assert ('foo',) == kwargs.get('positional_args')
def test_positional_args_proxied(self):
"""
Positional arguments supplied are proxied as kwarg.
"""
bl = BoundLogger(ReturnLogger(), [], {})
args, kwargs = bl.debug("event", "foo", bar="baz")
assert "baz" == kwargs.get("bar")
assert ("foo", ) == kwargs.get("positional_args")
def test_exception_exc_info_override(self):
"""
If *exc_info* is password to exception, it's used.
"""
bl = BoundLogger(ReturnLogger(), [], {})
assert ((), {"exc_info": 42, "event": "event"}) == bl.exception(
"event", exc_info=42
)
def _do_get_order_list(
args: TbServiceGetOrderDetailsArgs, logger: BoundLogger
) -> Optional[OrderDetailsResp]:
dtk = DtkSyncApi(SConfig.DTKAppKey, SConfig.DTKAppSecret)
ret = dtk.tb_service_get_order_details(args)
logger.bind(ret=ret).info("get data")
if ret is None:
return None
return OrderDetailsResp.from_result(ret)
def _process_order(self, order: OrderDto, logger: BoundLogger):
"""
处理一个订单的信息
:param order: 处理订单
:return:
"""
try:
return self._do_process_order(order, logger)
except Exception as e:
logger.bind(exception=e).error("process order failed")
async def route_ingest_message(
*,
app: web.Application,
scheduler: aiojobs.Scheduler,
logger: BoundLogger,
message: Dict[str, Any],
schema_id: int,
schema: Dict[str, Any],
topic: str,
partition: int,
offset: int,
) -> None:
"""Route a message known to be from the ook.ingest topic.
Parameters
----------
app : `aiohttp.web.Application`
The app.
scheduler : `aiojobs.Scheduler`
The aiojobs scheduler for jobs that handle the Kafka events.
logger
A structlog logger that is bound with context about the Kafka message.
message : `dict`
The deserialized value of the Kafka message.
schema_id : `int`
The Schema Registry ID of the Avro schema used to serialie the message.
topic : `str`
The name of the Kafka topic that the message was consumed from.
partition : `int`
The partition of the Kafka topic that the message was consumed form.
offset : `int`
The offset of the Kafka message.
"""
content_type = ContentType[message["content_type"]]
if content_type == ContentType.LTD_SPHINX_TECHNOTE:
await scheduler.spawn(
ingest_ltd_sphinx_technote(
app=app, logger=logger, url_ingest_message=message
)
)
elif content_type == ContentType.LTD_LANDER_JSONLD:
await scheduler.spawn(
ingest_ltd_lander_jsonld_document(
app=app, logger=logger, url_ingest_message=message
)
)
else:
logger.info(
"Ignoring ingest request for unsupported content type",
content_url=message["url"],
content_type=message["content_type"],
)
def write_csv(df: pd.DataFrame, path: pathlib.Path,
log: stdlib.BoundLogger) -> None:
"""Write `df` to `path` as a CSV with index set by `fix_df_index`."""
df = fix_df_index(df, log)
log.info("Writing DataFrame", current_index=df.index.names)
# A column with floats and pd.NA (which is different from np.nan) is given type 'object' and does
# not get formatted by to_csv float_format. Changing the pd.NA to np.nan seems to let convert_dtypes
# to change 'object' columns to 'float64' and 'Int64'.
df = df.replace({pd.NA: np.nan}).convert_dtypes()
# Format that outputs floats without a fraction as an integer without decimal point. Very large and small
# floats (uncommon in our data) are output in exponent format. We currently output a large number of fractional
# sig digits; 7 is likely enough but I don't see a way to limit them when formatting output.
df.to_csv(path, date_format="%Y-%m-%d", index=True, float_format="%.12g")
def _do_update_old_order(order: OrderDto, model: OrderModel,
logger: BoundLogger):
"""
更新一个订单信息
当前的订单信息为 order
数据库中的信息为 model
:param order:
:param model:
:param logger:
:return:
"""
model.order_ctime = order.order_ctime()
model.order_status = str(order.tk_status)
model.pay_price = order.ali_pay_price()
model.pay_time = order.pay_time()
model.end_time = order.end_time()
model.income = order.income()
model.score = (int(order.income() * 100), )
model.detail = order.to_dict()
if order.is_order_paid(): # 默认状态
model.status = OrderStatusEnum.wait
elif order.is_order_canceled(): # 需要查询之前的状态
if model.status == OrderStatusEnum.wait:
model.status = OrderStatusEnum.cancel
elif model.status == OrderStatusEnum.cancel: # 已经是这个状态 没有必要更新
pass
elif model.status == OrderStatusEnum.success:
logger.bind(order_no=order.trade_id).error("revoke score ?")
model.status = OrderStatusEnum.cancel
elif order.is_order_success() or order.is_order_done():
if model.status == OrderStatusEnum.wait: # 之前的状态是等待 现在变成 成功状态
event = f"购买: {order.trade_id}"
logic = UserV2Logic(logger)
logic.add_score(model.user, event, int(order.income() * 100))
model.status = OrderStatusEnum.success
elif model.status == OrderStatusEnum.cancel: # 取消之后不可能成功
logger.bind(
order_no=order.trade_id).error("sth impossible happened")
elif model.status == OrderStatusEnum.success: # 已经是这个状态 没有必要更新
pass
# noinspection PyArgumentList
model.save()
def disable_commit(db: Database, log: BoundLogger) -> Iterator:
restore = True
# If `db.session` already has its `commit` method disabled we won't try disabling *and* restoring it again.
if db.session.info.get("disabled", False):
restore = False
else:
log.debug("Temporarily disabling commit.")
db.session.info["disabled"] = True
db.session.info["logger"] = log
try:
yield
finally:
if restore:
log.debug("Reenabling commit.")
db.session.info["disabled"] = False
db.session.info["logger"] = None
def test_proxies_to_correct_method(self, method_name):
"""
The basic proxied methods are proxied to the correct counterparts.
"""
bl = BoundLogger(ReturnLogger(), [return_method_name], {})
assert method_name == getattr(bl, method_name)("event")
def _do_get_order_list(args: NewOrderArgs,
logger: BoundLogger) -> Optional[OrderDetailsResp]:
args.sid = SConfig.ZTKSid
ztk = ZTKSync(args.sid, logger)
ret = ztk.new_order(args)
if not isinstance(ret, dict):
logger.bind(ret=ret).error("get ztk failed")
return None
if "url" not in ret:
logger.bind(ret=ret).error("not found url")
return None
url = ret["url"]
data = requests.get(url)
j = data.json()
ret = OrderDetailsResp.from_result(j)
return ret
def build_bl(logger=None, processors=None, context=None):
"""
Convenience function to build BoundLogger with sane defaults.
"""
return BoundLogger(
logger or ReturnLogger(),
processors,
{}
)
def fix_df_index(df: pd.DataFrame, log: stdlib.BoundLogger) -> pd.DataFrame:
"""Return a `DataFrame` with the CAN CommonFields index or the unmodified input if already set."""
if df.index.names != COMMON_FIELDS_TIMESERIES_KEYS:
log.warning("Fixing DataFrame index", current_index=df.index.names)
if df.index.names != [None]:
df = df.reset_index(inplace=False)
df = df.set_index(COMMON_FIELDS_TIMESERIES_KEYS, inplace=False)
df = df.sort_index()
if "index" in df.columns:
# This is not expected in our normal code path but seems to sneak in occasionally
# when calling reset_index on a DataFrame that doesn't have a named index.
log.warning("Dropping column named 'index'")
df = df.drop(columns="index")
df = sort_common_field_columns(df)
return df
def transactional(db: Database, log: BoundLogger) -> Iterator:
"""Run a step function in an implicit transaction with automatic rollback or commit.
It will rollback in case of error, commit otherwise. It will also disable the `commit()` method
on `BaseModel.session` for the time `transactional` is in effect.
"""
try:
with disable_commit(db, log):
yield
log.debug("Committing transaction.")
db.session.commit()
except Exception:
log.warning("Rolling back transaction.")
raise
finally:
# Extra safe guard rollback. If the commit failed there is still a failed transaction open.
# BTW: without a transaction in progress this method is a pass-through.
db.session.rollback()
def index_and_sort(df: pd.DataFrame, index_names: List[str],
log: stdlib.BoundLogger) -> pd.DataFrame:
"""Return a `DataFrame` with index set to `index_names` if not already set, and rows and columns sorted."""
if df.index.names != index_names:
log.warning("Fixing DataFrame index", current_index=df.index.names)
if df.index.names != [None]:
df = df.reset_index(inplace=False)
df = df.set_index(index_names, inplace=False)
df = df.sort_index()
if "index" in df.columns:
# This is not expected in our normal code path but seems to sneak in occasionally
# when calling reset_index on a DataFrame that doesn't have a named index.
log.warning("Dropping column named 'index'")
df = df.drop(columns="index")
df = sort_common_field_columns(df)
return df
def test_stdlib_passthrough_attributes(self, attribute_name):
"""
stdlib logger attributes are also available in stdlib BoundLogger.
"""
stdlib_logger = logging.getLogger("Test")
stdlib_logger_attribute = getattr(stdlib_logger, attribute_name)
bl = BoundLogger(stdlib_logger, [], {})
bound_logger_attribute = getattr(bl, attribute_name)
assert bound_logger_attribute == stdlib_logger_attribute
def read_namespace(logger: BoundLogger) -> str:
"""Determine the namespace of the pod from the Kubernetes metadata.
Parameters
----------
logger : `structlog.stdlib.BoundLogger`
Logger to use for warnings if the namespace file couldn't be found.
Returns
-------
namespace : `str`
The namespace, or ``default`` if the namespace file is not present.
"""
path = Path("/var/run/secrets/kubernetes.io/serviceaccount/namespace")
try:
return path.read_text().strip()
except FileNotFoundError:
logger.warn(f"Namespace file {str(path)} not found, using 'default'")
return "default"
def cond_bind(log: BoundLogger,
state: Dict[str, Any],
key: str,
as_key: Optional[str] = None) -> BoundLogger:
"""Conditionally (on presence of key) build Structlog context."""
if as_key is None:
as_key = key
if key in state:
return log.bind(**{as_key: state[key]})
return log
def _clear_common_values(log: BoundLogger, existing_df, data_source,
index_fields, column_to_fill):
"""For index labels shared between existing_df and data_source, clear column_to_fill in existing_df.
existing_df is modified inplace. Index labels (the values in the index for one row) do not need to be unique in a
table.
"""
existing_df.set_index(index_fields, inplace=True)
data_source.set_index(index_fields, inplace=True)
common_labels_without_date = existing_df.index.intersection(
data_source.index)
if not common_labels_without_date.empty:
# Maybe only do this for rows with some value in column_to_fill.
existing_df.sort_index(inplace=True, sort_remaining=True)
existing_df.loc[common_labels_without_date, [column_to_fill]] = None
log.error(
"Duplicate timeseries data",
common_labels=common_labels_without_date.to_frame(
index=False).to_dict(orient="records"),
)
existing_df.reset_index(inplace=True)
data_source.reset_index(inplace=True)
async def delete_old_records(
*,
index: SearchIndex,
base_url: str,
surrogate_key: str,
logger: BoundLogger,
) -> None:
"""Delete records for a given URL that do not posess the current surrogate
key.
Parameters
----------
index
The Algolia search index.
base_url : `str`
The ``baseUrl`` property of the records.
surrogate_key : `str`
The value of ``surrogateKey`` for the current ingest. Records for the
``baseUrl`` that don't have this surrogate key value are deleted.
logger
A structlog logging instance.
"""
object_ids: List[str] = []
async for record in search_for_old_records(index=index,
base_url=base_url,
surrogate_key=surrogate_key):
if record["baseUrl"] != base_url:
logger.warning(f'baseUrl does not match: {record["baseUrl"]}')
continue
if record["surrogateKey"] == surrogate_key:
logger.warning(
f'surrogateKey matches current key: {record["surrogateKey"]}')
continue
object_ids.append(record["objectID"])
logger.info(
"Collected old objectIDs for deletion",
base_url=base_url,
object_id_count=len(object_ids),
)
await index.delete_objects_async(object_ids)
logger.info(
"Finished deleting expired objects",
base_url=base_url,
object_id_count=len(object_ids),
)
async def get_index(
logger: BoundLogger = Depends(logger_dependency), ) -> Index:
"""GET ``/example/`` (the app's external root).
Customize this handler to return whatever the top-level resource of your
application should return. For example, consider listing key API URLs.
When doing so, also change or customize the response model in
`example.models.Index`.
By convention, the root of the external API includes a field called
``metadata`` that provides the same Safir-generated metadata as the
internal root endpoint.
"""
# There is no need to log simple requests since uvicorn will do this
# automatically, but this is included as an example of how to use the
# logger for more complex logging.
logger.info("Request for application metadata")
metadata = get_metadata(
package_name="example",
application_name=config.name,
)
return Index(metadata=metadata)
async def process_edition_updated(
*,
app: web.Application,
logger: BoundLogger,
message: Dict[str, Any],
) -> None:
"""Process an ``edition.updated`` event from LTD Events.
Parameters
----------
app : `aiohttp.web.Application`
The app.
logger
A structlog logger that is bound with context about the Kafka message.
message : `dict`
The deserialized value of the Kafka message.
"""
logger.info("In process_edition_updated")
content_type = await classify_ltd_site(
http_session=app["safir/http_session"],
product_slug=message["product"]["slug"],
published_url=message["edition"]["published_url"],
)
logger.info("Classified LTD site", content_type=content_type)
ltd_document_types = {
ContentType.LTD_LANDER_JSONLD,
ContentType.LTD_SPHINX_TECHNOTE,
}
if content_type in ltd_document_types:
await queue_ltd_document_ingest(
app=app,
logger=logger,
content_type=content_type,
edition_updated_message=message,
)
def test_exception_maps_to_error(self):
bl = BoundLogger(ReturnLogger(), [return_method_name], {})
assert "error" == bl.exception("event")
def test_proxies_exception(self):
"""
BoundLogger.exception is proxied to Logger.error.
"""
bl = BoundLogger(ReturnLogger(), [return_method_name], {})
assert "error" == bl.exception("event")
