Аналіз доставки повідомлень з використанням Log-файлів

Для пошуку повідомлень, що пройшли через поштові сервери зазвичай використовується програма FmStat, але іноді потрібно більш детальний аналіз. Його варіанти ми і розглянемо в цій статті.

Маршрут “АРМ1 – АРМ2”

Аналіз Log-файлов АРМ1. Відправка повідомлення

Розглянемо схему, коли повідомлення передається від автоматизованого робочого місця 1 (АРМ1) на АРМ2, які обслуговуються різними серверами. Ці АРМ-и мають відповідно адреси

C:UA/ADMD:PRIVATBANK/PRMD:UCIH/ORG:CENTER/OU:OFFICE/PN:ARM1

и

 C:UA/ADMD:NBU/PRMD:U1H0/ORG:CRP/OU:ЦЕНТРАЛЬНА-РОЗРАХУНКОВА-ПАЛА/PN:ARM2

Log_ARM

 

Наше повідомлення формується скриптом script.bas за допомогою упаковки файлів, які поміщені в каталог    OutDir   := “..\Out”, і відправляється програмою TcpFoss. В результаті роботи скрипта в каталог FpkOutDir := “.\FPkOut” вміщено файл поштової кореспонденції (ФПК) з ім’ям Nf59ba4.fpk і з’явився слідуючий запис в Log-файлі 150610Xp.log обробника скрипта.

---[ Packed ]----------------------------------[ 10/06/2015 12:01:25 ]-
  FPK : G~20150610120125AARFSCFHE3QT0ED	29696	10/06/2015 12:01:25
  TYPE: Message  
  FROM: C:UA/ADMD:PRIVATBANK/PRMD:UCIH/ORG:CENTER/OU:OFFICE/PN:ARM1
  TO  : C:UA/ADMD:NBU/PRMD:U1H0/ORG:CRP/OU:ЦЕНТРАЛЬНА-РОЗРАХУНКОВА-ПАЛА/PN:ARM2
  RT  : 3	"deliver & read"
  Subj: Speed test
  File: "Письмо.doc"	7288	22/05/2015 09:40:24
  FPK Name:"Nf59ba4.fpk"

де:

  • FPK : ідентифікатор ФПК
  • TYPE: тип-повідомлення
  • FROM: адреса відправника повідомлення
  • TO : адреса отримувача повідомлення
  • RT : тип запитуваного звіту – запитаний звіт про доставку і про прочитання
  • Subj: тема повідомлення
  • File: ім’я файлу упакованого в повідомлення
  • FPK Name: ім’я файлу безпосередньо самого ФПК

Далі наш ФПК з ім’ям Nf59ba4.fpk був переданий програмою TcpFoss на поштовий сервер UCIH (ім’я вказується в рядку CONNECT) про що було зроблено запис у її Log-файлі 150610T0.LOG

10/06/15 12:01:28 CONNECT 1 UCIH 10.0.1.77 V4.6.5
 S0|Nf59ba4.fpk |            |10/06/15|12:01:25|7817     |12:01:28|12:01:28|7817
END CONNECTION 10.0.1.77 10/06/15 12:01:31 (S/R=7817 bytes Cps=2605 cps)

Аналіз Log-файлів поштового сервера UCIH. Прийом і відправлення повідомлення

Проведемо аналіз значимих Logфайлів сервера UCIH. В файлі 150610T1_SNTPC_1.LOG є запис про прийом файлу Nf59ba4.fpk на поштовий сервер від клієнта з ім’ям ARM1.

10/06/15 12:01:28 CONNECT 1 ARM1 10.0.1.77 V4.6.4
 R0|Nf59ba4.fpk |            |10/06/15|12:01:25|7817     |12:01:28|12:01:28|7817

 

Враховуючи алгоритм роботи поштового сервера  далі проаналізуємо Logфайл маршрутизатора поштового сервера 150610rt.log. У ньому існує наступний запис.

12:01:28  0........   (FROM: Dir: ARM1, Apf: T1_SNTPC_1)
 G~20150610120125AARFSCFHE3QT0ED  M  NF59BA4.FPK
       U1H0                       0  C:UA/ADMD:NBU/PRMD:U1H0/ORG:CRP/OU:ЦЕНТРАЛЬНА-РОЗРАХУНКОВА-ПАЛА/PN:ARM2

 

Даний запис означає, що був прийнятий ФПК з ім’ям Nf59ba4.fpk. Це повідомленняМ“.  ФПК прийнят з напрямку ARM1, АПФ-ом T1_SNTPC_1 (FROM: Dir: ARM1, Apf: T1_SNTPC_1). Вказано адресу одержувача, і поштовий ящик U1H0, в який і помістили файл з ім’ям Nf59ba4.fpk. Крім цього записується ідентифікатор повідомлення G~20150610120125AARFSCFHE3QT0ED, який не змінюється в процесі руху повідомлення по системі. Він збігається з ідентифікатором, який був присвоєний повідомленням в момент його створення.

Враховуючи, що наше повідомлення має бути передано на поштовий сервер з ім’ям U1H0 за допомогою АПФа TcpFoss знайдемо про це запис. Запис про передачу цього повідомлення знаходиться у файлі 150610T1_SNTPC_0.LOG

10/06/15 12:01:37 CONNECT 6 U1H0 10.0.1.186 V4.6.5
 S0|NF59BA4.FPK |            |10/06/15|12:01:28|7861     |12:01:38|12:01:38|7861
END CONNECTION U1H0 10/06/15 12:01:39 (S/R=7861 bytes Cps=7861 cps)

 

Отже наш ФПК успішно переданий на поштовий сервер U1H0.

Примітка: Задача TcpFoss одночасно веде роботу кількома потоками і кожний із потоків веде свій  Log-файл. Отже запис про  прийом/передачу файлів може бути в любом з її Log-файлів.

Аналіз проходження звіту на поштовом сервері

Як було сказано вище, в момент пакування ФПК були запитані звіти про доставку та прочитання. Перевіримо, чи проходили такі звіти. Для цього відкриємо Log-файл маршрутизатора 150610rt.log та по ідентифікатору нашего повідомлення G~20150610120125AARFSCFHE3QT0ED знайдемо запис про те, що проходив звіт “R”  і цей звіт відправлений у поштову скриньку ARM1. Звіт знаходиться у файлі з ім’ям 0L295ER.REP

12:01:47  0........   (FROM: Dir: U1H0, Apf: T1_SNTPC_0)
 G~20150610120125AARFSCFHE3QT0ED  R  G~20150610120125AARFSCFHE3QT0EDRR_0L295ER.REP
       ARM1                       0  C:UA/ADMD:PRIVATBANK/PRMD:UCIH/ORG:CENTER/OU:OFFICE/PN:ARM1

 

і далі, цей звіт передано програмою TcpFoss на робоче місце ARM1.

10/06/15 12:01:49 CONNECT 10 ARM1 10.0.1.77 V4.6.4
 S0|0L295ER.REP |            |10/06/15|12:01:47|663      |12:01:49|12:01:49|663
END CONNECTION ARM1 10/06/15 12:01:50 (S/R=663 bytes Cps=663 cps)

Аналіз проходження звіту на робочому місці ARM1

Подивимося, що реально знаходиться в цьому звіті. Запис про це містить Logфайл обробника скрипта 150610Xp.log

---[ Unpacked ]----------------------------------[ 10/06/2015 12:01:49 ]-
  FPK : G~20150610120125AARFSCFHE3QT0ED	0	10/06/2015 12:02:03
  TYPE: Report
  CODE: 3 	"unroute"	C:UA/ADMD:NBU/PRMD:U1H0/ORG:CRP/OU:ЦЕНТРАЛЬНА-РОЗРАХУНКОВА-ПАЛА/PN:ARM2	10/06/2015 12:02:02
  FROM: HOST:U1H0
  TO  : C:UA/ADMD:PRIVATBANK/PRMD:UCIH/ORG:CENTER/OU:OFFICE/PN:ARM1
  RT  : 1	"deliver"
  Subj: Speed test
  FPK Name:"G~20150610120125AARFSCFHE3QT0EDRR_0L295ER.REP"

 

Цей запис означає наступне. Був розпакований звітTYPE: Report” на повідомлення з ідентифікатором “FPK : G~20150610120125AARFSCFHE3QT0ED“. Звіт був про недоставлення повідомлення, “CODE: 3 “unroute” C:UA/ADMD:NBU/PRMD:U1H0/ORG:CRP/OU:ЦЕНТРАЛЬНА-РОЗРАХУНКОВА-ПАЛА/PN:ARM2“. Тобто немає маршруту для повідомлення з такою адресою одержувача. Цей звіт сформував поштовий сервер U1H0 “FROM: HOST:U1H0

Маршрут “інтерактивний клієнт -інтерактивний клієнт”

Для простоти розглянемо обслуговування двох клієнтів одним поштовим сервером.

Log_client

 

На відміну від роботи з АРМ-ами в процесі передачі повідомлення програма TcpFoss не бере участі. І запис про таке повідомлення і про проходження звітів на нього буде тільки в Logфайлі маршрутизатора 150610rt.log.

14:56:27  0........   (FROM: Dir: СТЕПАНОВ, Apf: FossDoc transport)
 F~20150610145627AARFMR2IFWIJDIM  M  L03OP636.UUH
       СИДОРОВ                    0  C:UA/ADMD:PRIVATBANK/PRMD:UCIH/ORG:CENTER/OU:ПРИВАТБАНК/PN:СИДОРОВ
 
14:56:27  0........
 F~20150610145627AARFMR2IFWIJDIM  R  F~20150610145627AARFMR2IFWIJDIMRR_0un87OK.rep
       СТЕПАНОВ                   0  C:UA/ADMD:PRIVATBANK/PRMD:UCIH/ORG:CENTER/OU:ПРИВАТБАНК/PN:СТЕПАНОВ
 
14:56:58  0........   (FROM: Dir: СИДОРОВ, Apf: FossDoc transport)
 F~20150610145627AARFMR2IFWIJDIM  R  0B92RS2M.U9C
       СТЕПАНОВ         

 

Із записів в Logфайлі видно що АПФ FossDoc transport від імені користувача СТЕПАНОВ передав повідомлення на поштовий сервер (FROM: Dir: СТЕПАНОВ, Apf: FossDoc transport) і це повідомлення було поміщено в поштову скриньку СИДОРОВ. Далі поштовим сервером був сформований звіт про доставку повідомлення (другий запис) і від імені СИДОРОВ(FROM: Dir: СИДОРОВ, Apf: FossDoc transport) отриманий звіт про прочитання (третій запис). Ідентифікатори повідомлення і звітів збігаються.