La commande "awk" suivante vous permettra d'obtenir, pour le fichier chrono.log en cours, le nombre de transactions par tranche de 10 minutes, total, une analyse par processus HR, code action fonctionnelle, type de message, et le différentiel des connexions et déconnexions (ce qui correspond au nombre maxi d'utilisateurs connectés pour peu que vous démarriez votre analyse à un moment ou personne n'est connecté).
En fonction de l'usage que vous ferez de vos mesures, il pourra être nécessaire de faire un tri dans les messages (par exemple, les demandes de rafraichissement de l'état d'avancement des query TP tous les 1/10e de seconde peut vous perturber).
Il est préférable de faire vos analyse journée par journée.
Ci dessous un exemple (pour une date au 31 juillet 2009) :
grep "2009-07-31" chrono.log* | sed 's/^[^:]*://' | sort |
awk -F'|' 'BEGIN {
user_cnt=0
user_cnx=0
max_cnx=0
user_dcx=0
total_bhr_t=-1
mins_bhr_t=-1
digix=0
delai_cnt_0s=0
delai_cnt_1s=0
delai_cnt_2s=0
delai_cnt_3s=0
delai_cnt_4s=0
delai_cnt_5s=0
delai_cnt_6s=0
delai_cnt_7s=0
delai_cnt_8s=0
delai_cnt_9s=0
delai_cnt_ns=0
date_prv="0001-01-01 00:00"
}
substr($6,9,8) ~ /BNM/ {
p=substr($6,9,5); ip[p]=$4; np[p]++;
if (np[p]==1) {Mp[p]=ip[p]; mp[p]=ip[p]};
sp[p]+=ip[p];
if (ip[p]>Mp[p]) Mp[p]=ip[p];
if (ip[p]<mp[p]) mp[p]=ip[p];
if ($5<=1000) delai_cnt_0s++;
if ($5<=2000 && $5>1000) delai_cnt_1s++;
if ($5<=3000 && $5>2000) delai_cnt_2s++;
if ($5<=4000 && $5>3000) delai_cnt_3s++;
if ($5<=5000 && $5>4000) delai_cnt_4s++;
if ($5<=6000 && $5>5000) delai_cnt_5s++;
if ($5<=7000 && $5>6000) delai_cnt_6s++;
if ($5<=8000 && $5>7000) delai_cnt_7s++;
if ($5<=9000 && $5>8000) delai_cnt_8s++;
if ($5<=10000 && $5>9000) delai_cnt_9s++;
if ($5>10000) delai_cnt_ns++;
}
substr($6,9,31) ~ /BNM *...................03CA/ {
a=substr($6,40,8); ia[a]=$4; na[a]++;
if (na[a]==1) {Ma[a]=ia[a]; ma[a]=ia[a]};
sa[a]+=ia[a];
if (ia[a]>Ma[a]) Ma[a]=ia[a];
if (ia[a]<ma[a]) ma[a]=ia[a];
}
{
m=substr($6,17,2); im[m]=$4; nm[m]++;
if (nm[m]==1) {Mm[m]=im[m]; mm[m]=im[m]};
sm[m]+=im[m];
if (im[m]>Mm[m]) Mm[m]=im[m];
if (im[m]<mm[m]) mm[m]=im[m];
}
{
mins_bhr_t++;
date_mins_trc=substr($1,1,15) "0";
if (max_cnx<user_cnt) max_cnx=user_cnt;
if (date_mins_trc!=date_prv) {
print date_prv ", BHR Transactions/10mn : " mins_bhr_t, ", Connections delta (from the beginning) : " user_cnt ;
mins_bhr_t=0;}
date_prv=date_mins_trc;
}
$6 ~ /XXXXXXXXXXXXXXXX00/ {
user_cnt++;
user_cnx++}
$6 ~ /XXXXXXXXXXXXXXXX49/ {
user_cnt--;
user_dcx++}
END {
print "Tracked connections / deconnections : " user_cnx " / " user_dcx ", Max connections delta : " max_cnx ;
print "BHR transactions (total) : " NR;
print "BHR transactions by message type: " ;
for ( m in im ) { printf("- Message : %s ,Nb transactions : %i, Response time (avg / min / max) : %i / %i / %i ms\n",m,nm[m],sm[m]/nm[m],mm[m],Mm[m]) };
print "BHR transactions by functionnal action code : " ;
for ( a in ia ) { printf("- Action : %s ,Nb transactions : %i, Response time (avg / min / max) : %i / %i / %i ms\n",a,na[a],sa[a]/na[a],ma[a],Ma[a]) };
print "BHR transactions by process code : " ;
for ( p in ip ) { printf("- Process : %s ,Nb transactions : %i, Response time (avg / min / max) : %i / %i / %i ms\n",p,np[p],sp[p]/np[p],mp[p],Mp[p]) };
print "BHR response time distribution for process calls: ";
print "- <1s : " delai_cnt_0s;
print "- <2s : " delai_cnt_1s;
print "- <3s : " delai_cnt_2s;
print "- <4s : " delai_cnt_3s;
print "- <5s : " delai_cnt_4s;
print "- <6s : " delai_cnt_5s;
print "- <7s : " delai_cnt_6s;
print "- <8s : " delai_cnt_7s;
print "- <9s : " delai_cnt_8s;
print "- <10 : " delai_cnt_9s;
print "- >10 : " delai_cnt_ns;
} '
Exemple de résultat :
...
2009-06-16 08:50, BHR Transactions/10mn : 4 , Connections delta (from the beginning) : 0
2009-06-16 09:00, BHR Transactions/10mn : 4 , Connections delta (from the beginning) : 0
2009-06-16 09:10, BHR Transactions/10mn : 38 , Connections delta (from the beginning) : 1
2009-06-16 09:20, BHR Transactions/10mn : 196 , Connections delta (from the beginning) : 4
2009-06-16 09:30, BHR Transactions/10mn : 4 , Connections delta (from the beginning) : 4
2009-06-16 09:40, BHR Transactions/10mn : 5 , Connections delta (from the beginning) : 4
2009-06-16 09:50, BHR Transactions/10mn : 52 , Connections delta (from the beginning) : 5
2009-06-16 10:00, BHR Transactions/10mn : 109 , Connections delta (from the beginning) : 5
...
Tracked connections / deconnections : 12 / 8, Max connections delta : 6
BHR transactions (total) : 1281
BHR transactions by message type:
- Message : 27 ,Nb transactions : 493, Response time (avg / min / max) : 55 / 5 / 1268 ms
- Message : 46 ,Nb transactions : 221, Response time (avg / min / max) : 110 / 8 / 2506 ms
- Message : 3E ,Nb transactions : 2, Response time (avg / min / max) : 518 / 213 / 824 ms
- Message : 00 ,Nb transactions : 12, Response time (avg / min / max) : 162 / 1 / 1401 ms
- Message : <> ,Nb transactions : 9, Response time (avg / min / max) : 8 / 0 / 78 ms
- Message : 49 ,Nb transactions : 8, Response time (avg / min / max) : 115 / 2 / 554 ms
- Message : 02 ,Nb transactions : 2, Response time (avg / min / max) : 9964 / 7642 / 12287 ms
- Message : 30 ,Nb transactions : 186, Response time (avg / min / max) : 85 / 10 / 4264 ms
- Message : 1M ,Nb transactions : 2, Response time (avg / min / max) : 21 / 1 / 41 ms
- Message : 41 ,Nb transactions : 2, Response time (avg / min / max) : 1412 / 420 / 2404 ms
- Message : 2B ,Nb transactions : 173, Response time (avg / min / max) : 5 / 4 / 46 ms
- Message : 1P ,Nb transactions : 171, Response time (avg / min / max) : 33 / 6 / 458 ms
BHR transactions by functionnal action code :
- Action : MGC ,Nb transactions : 8, Response time (avg / min / max) : 157 / 39 / 303 ms
- Action : DEFAULT ,Nb transactions : 156, Response time (avg / min / max) : 43 / 5 / 710 ms
- Action : PAP ,Nb transactions : 156, Response time (avg / min / max) : 68 / 6 / 1268 ms
BHR transactions by GD process code :
- Process : FS001 ,Nb transactions : 1, Response time (avg / min / max) : 710 / 710 / 710 ms
- Process : AS90P ,Nb transactions : 3, Response time (avg / min / max) : 105 / 22 / 186 ms
- Process : AS800 ,Nb transactions : 103, Response time (avg / min / max) : 38 / 7 / 555 ms
- Process : FS901 ,Nb transactions : 438, Response time (avg / min / max) : 54 / 6 / 4264 ms
- Process : AS003 ,Nb transactions : 38, Response time (avg / min / max) : 87 / 10 / 303 ms
- Process : AS005 ,Nb transactions : 271, Response time (avg / min / max) : 63 / 5 / 1268 ms
- Process : AS00P ,Nb transactions : 1, Response time (avg / min / max) : 269 / 269 / 269 ms
BHR response time distribution for GD process calls:
- <1s : 1057
- <2s : 12
- <3s : 0
- <4s : 0
- <5s : 1
- <6s : 1
- <7s : 0
- <8s : 0
- <9s : 0
- <10 : 0
- >10 : 0
...
A noter :
- Un "connection delta" peut être négatif puisque c'est un delta ! Ceci justifie de faire un extrait quotidien pour n'avoir que les messages du jour (cela met les compteurs à zéro pour la journée). Le "Max connections delta" correspond alors au nombre maximum d'utilisateurs connectés simultanément.
- Une fermeture applicative provoquera des déconnexions sans trace dans les logs, d'ou un delta positif en fin de journée
- Un cas de delta négatif signifie que l'on a démarré l'analyse en milieu de journée, donc que l'on a raté des messages de connexions.
Autre point :
les temps BHR ne permettent pas de connaître les temps vus par l'utilisateur.
Une transaction utilisateur peut se composer de plusieurs transactions BHR.
Suite à quelques tests, j’ai pu noter :
- Connexion : 1 transaction BHR message type "00"
- Affichage d'une page sans données : pas de transaction BHR
- Selection pop par bandeau : 1 transaction BHR message type "1P" si population vide
- Selection pop par bandeau : 1 transaction BHR "1P" ... puis affichage des données fonctionnelles (cf ligne suivante)
- Affichage de données fonctionnelles : 1 ou plusieurs transactions BHR "27" (et tous les 5 dossiers si navigation sur la population)
- Changement d'écran sans réinitialisation de population : idem
- Changement d'onglet sans réinitialisation de population : pas de transaction BHR
- Supplément pour affichage d'un BLOB (ex photo de l'agent) : 1 ou plusieurs transactions BHR "4C"
- Mise à jour simple : 1 transaction BHR "30" (puis 1 ou plusieurs "27" si des données ayant évolué doivent être réaffichées)
- Ouverture d’une pop-up reglementaire : 2 transactions BHR "46", 1 transaction "1P", plusieurs "27"
- Déconnexion : 1 transaction BHR "49" et 1 transaction "04"
- Attente du resultat d'un Query TP : 1 transaction "2B" via TYBXBOR tous les 1/10e de seconde environ
A ceci s’ajoutera le temps réseau et l’activité du poste client (Applet, JavaScripts).
Aucun commentaire:
Enregistrer un commentaire