13 19:00:51.967479233 I CMS -> TCS_OPEN_SESSION_REQ{session=167123, channel=1, dni=1234567, ani=88886130(2), uui=}
13 19:00:51.967590983 I add session=167123
13 19:00:51.967683733 I DMS <- TCS_CHECK_BLACKLIST_REQ{session=167123, service_type_id=2, calling_num=88886130}
13 19:00:51.969900649 I DMS -> TCS_CHECK_BLACKLIST_RSP{session=167123, is_blocked=0, ret=0}
13 19:00:51.969973066 I CMS <- TCS_OPEN_SESSION_RSP{session=167123, script=1, script_parameter=(0, 0), user_input_wait=0, result=0, cause=0}
13 19:01:07.487790968 I CMS -> TCS_AUTH_CARD_REQ{session=167123, card=}
13 19:01:07.487949801 I DMS <- TCS_AUTHORIZE_CARD_REQ{session=167123, cpn=88886130, card_num=102166539010}
13 19:01:07.502334384 I DMS -> TCS_AUTHORIZE_CARD_RSP{session=167123, card=102166539010, state=1, is_pin=0, lcn=, cmid=-1, cmmd=2, ret=0}
13 19:01:07.502416301 I DMS <- TCS_LOCK_CARD_REQ{session=167123, card=102166539010, bf=2}
13 19:01:07.512900218 I DMS -> TCS_LOCK_CARD_RSP{session=167123, card=102166539010, amount=9, fraction=62, ret=0}
13 19:01:07.512988218 I CMS <- TCS_AUTH_CARD_RSP{session=167123, result=0, cause=0, blocked=0, in_use=0, is_pin=0, menu=0, bi=2, cb=9, cbf=62}
13 19:01:26.596495783 I CMS -> TCS_SERVICE_REQ{session=167123, action_type=0, service_num=809*, user_selection=001}
13 19:01:26.596664533 I DMS <- TCS_INITIATE_CALL_REQ{session=167123, card=102166539010, ani=88886130, inc=1234567, out=809*, saving=Y}
13 19:01:26.629603534 I DMS -> TCS_INITIATE_CALL_RSP{session=167123, card=102166539010, call=6105846, duration=3600, ret=0}
13 19:01:26.629692117 I CMS <- TCS_SERVICE_RSP{session=167123, result=0, cause=0, ani=4951111111(3), dni=809(1), channel=3, cdi=1, limit=3600}
13 19:01:30.347514196 I CMS -> TCS_CALL_PROGRESS_NTF{session=167123, result=4, timestamp=10:01:30}
13 19:01:30.347643446 I CMS <- TCS_DTMF_REQ{session=167123}
13 19:01:30.347709113 I DMS <- TCS_COMPLETE_CALL_REQ{session=167123, card=102166539010, call=6105846, duration=0}
13 19:01:30.348278196 I CMS -> TCS_DTMF_RSP{session=167123, num_dtmf_entered18, dtmf_entered**********880#809*}
13 19:01:30.348348696 I DMS <- TCS_WRITE_DTMF_NTF{session=167123, timestamp1158127251, num_dtmf_entered18, dtmf_entered**********880#809*}
13 19:01:30.379593447 I DMS -> TCS_COMPLETE_CALL_RSP{session=167123, card=102166539010, call=6105846, cost=0, ret=0}
13 19:01:51.718947593 I CMS -> TCS_SERVICE_REQ{session=167123, action_type=0, service_num=84951000000, user_selection=001}
13 19:01:51.719028426 I DMS <- TCS_INITIATE_CALL_REQ{session=167123, card=102166539010, ani=88886130, inc=1234567, out=84951000000, saving=Y}
13 19:01:51.766589676 I DMS -> TCS_INITIATE_CALL_RSP{session=167123, card=102166539010, call=6105864, duration=3600, ret=0}
13 19:01:51.766693260 I CMS <- TCS_SERVICE_RSP{session=167123, result=0, cause=0, ani=495111111(3), dni=84951000000(1), channel=3, cdi=1, limit=3600}
13 19:01:56.573567338 I CMS -> TCS_CHANNEL_OUTSEIZED_NTF{session=167123, span=17, channel=15}
13 19:01:56.573734755 I DMS <- TCS_CALL_OUTSEIZED_NTF{session=167123, span=17, channel=15}
13 19:01:56.668603422 I CMS -> TCS_CALL_PROGRESS_NTF{session=167123, result=0, timestamp=10:01:56}
13 19:01:56.668697505 I DMS <- TCS_START_CALL_REQ{session=167123, card=102166539010, call=6105864}
13 19:01:56.683766088 I DMS -> TCS_START_CALL_RSP{session=167123, card=102166539010, call=6105864}
13 19:02:32.161183721 I CMS -> TCS_CALL_COMPLETED_NTF{session=167123, initiator=1, timestamp=10:02:32}
13 19:02:32.161338721 I DMS <- TCS_COMPLETE_CALL_REQ{session=167123, card=102166539010, call=6105864, duration=36}
13 19:02:32.176583554 I DMS -> TCS_COMPLETE_CALL_RSP{session=167123, card=102166539010, call=6105864, cost=3000, ret=0}
13 19:02:56.730119198 I CMS -> TCS_SERVICE_REQ{session=167123, action_type=0, service_num=84951000000, user_selection=001}
13 19:02:56.730314614 I DMS <- TCS_INITIATE_CALL_REQ{session=167123, card=102166539010, ani=88886130, inc=3365432, out=84951000000, saving=Y}
13 19:02:56.763168281 I DMS -> TCS_INITIATE_CALL_RSP{session=167123, card=102166539010, call=6105907, duration=0, ret=0}
13 19:02:56.763280614 I CMS <- TCS_SERVICE_RSP{session=167123, result=0, cause=0, ani=4952287601(3), dni=84951000000(1), channel=3, cdi=1, limit=3600}
13 19:03:01.429774860 I CMS -> TCS_CHANNEL_OUTSEIZED_NTF{session=167123, span=2, channel=6}
13 19:03:01.429895860 I DMS <- TCS_CALL_OUTSEIZED_NTF{session=167123, span=2, channel=6}
13 19:03:01.432477027 I CMS -> TCS_CALL_PROGRESS_NTF{session=167123, result=0, timestamp=10:03:01}
13 19:03:01.432629360 I DMS <- TCS_START_CALL_REQ{session=167123, card=102166539010, call=6105907}
13 19:03:01.450101776 I DMS -> TCS_START_CALL_RSP{session=167123, card=102166539010, call=6105907}
13 19:09:20.312614582 I CMS -> TCS_CALL_COMPLETED_NTF{session=167123, initiator=1, timestamp=10:09:20}
13 19:09:20.312763415 I DMS <- TCS_COMPLETE_CALL_REQ{session=167123, card=102166539010, call=6105907, duration=379}
13 19:09:20.328827998 I DMS -> TCS_COMPLETE_CALL_RSP{session=167123, card=102166539010, call=6105907, cost=14000, ret=0}
13 19:09:20.498619748 I CMS -> TCS_SESSION_COMPLETE_NTF{session=167123, cause=0, timestamp=10:09:20}
13 19:09:20.498791665 I DMS <- TCS_UNLOCK_CARD_REQ{session=167123, card=102166539010}
13 19:09:20.508302248 I DMS -> TCS_UNLOCK_CARD_RSP{session=167123, card=102166539010, ret=0}