Processing time statistics of invite authentication and authorization requests of the AAA radius server

 

Emin Gabrielyan

 

Created or modified: on 2011-02-25 by Emin, on 2011-02-25 by Emin

 

 

Processing time statistics of invite authentication and authorization requests of the AAA radius server 1

Updates of 2011-02-25. 1

Introduction. 4

References. 7

 

Updates of 2011-02-25

 

Here are the stats for the morning period combining the radius log files of 10 consecutive days. A period from 2011-02-10 through 2011-02-19 was taken. Both, for the total processing time and for the SQL query, the chart shows the respective min/avg/max times in intervals of about 63 seconds. The chart shows that the gap between minimum SQL time and minimum total time is large, while there is almost no gap between maximum SQL and total time. That means that the SQL query is the time consuming processing responsible for the peaks.

 

[zip]

 

The command line below shows the retrieval of the data from the 10 daily log files:

fraud-control:/home/folders/110225-invites# head -7000111 /home/var/log/radius/11021?,*,*,0,rotated,radius.log | perl -ne 'print "$1,$2,$3,$4\n" if(/^([^ ]+ +[0-9]+) +([0-9:]+): \.\.\.Done Authorize\/INVITE in ([0-9.]+) seconds, ([0-9.]+) spent in SQL queries\.$/)' > 11021x.csv

fraud-control:/home/folders/110225-invites#

fraud-control:/home/folders/110225-invites#

[log]

 

The following printout shows all cases during 10 days when the processing time exceeded the limit of 1.8 seconds.

fraud-control:/home/folders/110225-invites#

fraud-control:/home/folders/110225-invites# head -7000111 /home/var/log/radius/11021?,*,*,0,rotated,radius.log | perl -ne 'if(/^([^ ]+ +[0-9]+) +([0-9:]+): \.\.\.Done Authorize\/INVITE in ([0-9.]+) seconds, ([0-9.]+) spent in SQL queries\.$/){$date=$1; $time=$2; $total=$3; $sql=$4; print if($total > 1.8)}'

Feb 10 00:13:02: ...Done Authorize/INVITE in 2.337121 seconds, 2.303154 spent in SQL queries.

Feb 10 00:14:19: ...Done Authorize/INVITE in 2.286909 seconds, 2.279432 spent in SQL queries.

Feb 10 00:14:42: ...Done Authorize/INVITE in 2.977857 seconds, 2.961442 spent in SQL queries.

Feb 10 00:17:08: ...Done Authorize/INVITE in 6.970840 seconds, 6.954547 spent in SQL queries.

Feb 10 00:17:48: ...Done Authorize/INVITE in 1.884295 seconds, 1.846193 spent in SQL queries.

Feb 10 00:19:23: ...Done Authorize/INVITE in 2.547287 seconds, 2.514906 spent in SQL queries.

Feb 10 00:19:41: ...Done Authorize/INVITE in 1.937329 seconds, 1.899319 spent in SQL queries.

Feb 10 00:21:35: ...Done Authorize/INVITE in 2.069176 seconds, 2.053005 spent in SQL queries.

Feb 10 00:23:11: ...Done Authorize/INVITE in 1.840151 seconds, 1.803147 spent in SQL queries.

Feb 10 00:26:08: ...Done Authorize/INVITE in 2.516623 seconds, 2.481298 spent in SQL queries.

Feb 10 00:26:17: ...Done Authorize/INVITE in 2.901216 seconds, 2.888155 spent in SQL queries.

Feb 10 00:35:06: ...Done Authorize/INVITE in 16.532862 seconds, 16.516768 spent in SQL queries.

Feb 10 00:35:32: ...Done Authorize/INVITE in 12.137381 seconds, 12.121088 spent in SQL queries.

Feb 10 00:35:53: ...Done Authorize/INVITE in 10.021294 seconds, 10.004296 spent in SQL queries.

Feb 10 01:19:17: ...Done Authorize/INVITE in 1.816769 seconds, 1.782750 spent in SQL queries.

Feb 10 01:24:05: ...Done Authorize/INVITE in 1.953216 seconds, 1.719869 spent in SQL queries.

Feb 10 01:33:08: ...Done Authorize/INVITE in 2.439728 seconds, 2.401678 spent in SQL queries.

Feb 11 00:14:02: ...Done Authorize/INVITE in 5.921159 seconds, 5.904923 spent in SQL queries.

Feb 11 00:14:45: ...Done Authorize/INVITE in 16.555922 seconds, 16.539499 spent in SQL queries.

Feb 11 00:15:05: ...Done Authorize/INVITE in 2.150909 seconds, 2.136454 spent in SQL queries.

Feb 11 00:16:27: ...Done Authorize/INVITE in 6.324782 seconds, 6.308384 spent in SQL queries.

Feb 11 00:16:38: ...Done Authorize/INVITE in 7.127000 seconds, 7.113161 spent in SQL queries.

Feb 11 00:16:51: ...Done Authorize/INVITE in 6.782480 seconds, 6.766064 spent in SQL queries.

Feb 11 00:17:26: ...Done Authorize/INVITE in 6.221104 seconds, 6.213083 spent in SQL queries.

Feb 11 00:35:13: ...Done Authorize/INVITE in 2.086278 seconds, 2.038200 spent in SQL queries.

Feb 11 00:36:35: ...Done Authorize/INVITE in 3.799646 seconds, 3.783376 spent in SQL queries.

Feb 11 00:37:05: ...Done Authorize/INVITE in 2.105300 seconds, 2.078072 spent in SQL queries.

Feb 11 00:37:19: ...Done Authorize/INVITE in 4.053466 seconds, 4.040252 spent in SQL queries.

Feb 11 00:37:48: ...Done Authorize/INVITE in 4.897960 seconds, 4.889966 spent in SQL queries.

Feb 11 02:49:08: ...Done Authorize/INVITE in 2.331068 seconds, 2.277840 spent in SQL queries.

Feb 12 00:13:49: ...Done Authorize/INVITE in 3.998622 seconds, 3.989561 spent in SQL queries.

Feb 12 00:17:50: ...Done Authorize/INVITE in 3.541310 seconds, 3.533445 spent in SQL queries.

Feb 12 00:19:47: ...Done Authorize/INVITE in 2.187877 seconds, 2.155431 spent in SQL queries.

Feb 12 00:22:47: ...Done Authorize/INVITE in 2.297110 seconds, 2.289274 spent in SQL queries.

Feb 12 00:22:56: ...Done Authorize/INVITE in 3.974638 seconds, 3.966803 spent in SQL queries.

Feb 12 00:32:20: ...Done Authorize/INVITE in 2.183320 seconds, 2.152263 spent in SQL queries.

Feb 12 00:32:59: ...Done Authorize/INVITE in 8.422195 seconds, 8.413442 spent in SQL queries.

Feb 12 00:33:36: ...Done Authorize/INVITE in 14.054000 seconds, 14.036947 spent in SQL queries.

Feb 12 00:33:58: ...Done Authorize/INVITE in 10.231268 seconds, 10.212751 spent in SQL queries.

Feb 12 01:05:57: ...Done Authorize/INVITE in 83.909921 seconds, 83.893888 spent in SQL queries.

Feb 12 01:09:10: ...Done Authorize/INVITE in 184.485879 seconds, 184.464057 spent in SQL queries.

Feb 12 01:09:21: ...Done Authorize/INVITE in 3.280980 seconds, 3.267050 spent in SQL queries.

Feb 12 01:09:26: ...Done Authorize/INVITE in 4.108739 seconds, 4.095458 spent in SQL queries.

Feb 12 01:09:30: ...Done Authorize/INVITE in 3.197555 seconds, 3.184314 spent in SQL queries.

Feb 12 01:09:36: ...Done Authorize/INVITE in 4.908167 seconds, 4.894806 spent in SQL queries.

Feb 12 01:09:40: ...Done Authorize/INVITE in 4.001030 seconds, 3.984863 spent in SQL queries.

Feb 12 01:09:44: ...Done Authorize/INVITE in 3.017190 seconds, 3.004105 spent in SQL queries.

Feb 12 01:09:48: ...Done Authorize/INVITE in 3.804769 seconds, 3.791640 spent in SQL queries.

Feb 12 01:09:50: ...Done Authorize/INVITE in 2.166331 seconds, 2.118919 spent in SQL queries.

Feb 12 01:09:54: ...Done Authorize/INVITE in 4.014446 seconds, 4.001206 spent in SQL queries.

Feb 12 01:09:58: ...Done Authorize/INVITE in 3.735931 seconds, 3.722544 spent in SQL queries.

Feb 12 01:10:01: ...Done Authorize/INVITE in 2.094899 seconds, 2.061433 spent in SQL queries.

Feb 12 01:10:37: ...Done Authorize/INVITE in 35.772030 seconds, 35.721273 spent in SQL queries.

Feb 12 01:25:31: ...Done Authorize/INVITE in 4.668850 seconds, 4.639732 spent in SQL queries.

Feb 13 00:01:39: ...Done Authorize/INVITE in 3.075384 seconds, 3.046319 spent in SQL queries.

Feb 13 00:03:11: ...Done Authorize/INVITE in 2.168666 seconds, 2.134615 spent in SQL queries.

Feb 13 00:04:36: ...Done Authorize/INVITE in 1.955393 seconds, 1.939399 spent in SQL queries.

Feb 13 00:04:56: ...Done Authorize/INVITE in 3.808061 seconds, 3.800494 spent in SQL queries.

Feb 13 00:07:29: ...Done Authorize/INVITE in 3.152555 seconds, 3.114357 spent in SQL queries.

Feb 13 00:19:05: ...Done Authorize/INVITE in 1.928134 seconds, 1.920249 spent in SQL queries.

Feb 13 00:19:16: ...Done Authorize/INVITE in 2.139499 seconds, 2.131895 spent in SQL queries.

Feb 13 00:28:03: ...Done Authorize/INVITE in 2.148837 seconds, 2.111836 spent in SQL queries.

Feb 14 00:00:58: ...Done Authorize/INVITE in 1.901055 seconds, 1.867508 spent in SQL queries.

Feb 14 00:01:04: ...Done Authorize/INVITE in 4.364303 seconds, 4.347779 spent in SQL queries.

Feb 14 00:03:28: ...Done Authorize/INVITE in 19.567990 seconds, 19.528405 spent in SQL queries.

Feb 14 00:04:10: ...Done Authorize/INVITE in 4.127802 seconds, 4.114418 spent in SQL queries.

Feb 14 00:04:48: ...Done Authorize/INVITE in 2.497693 seconds, 2.490069 spent in SQL queries.

Feb 14 00:07:31: ...Done Authorize/INVITE in 2.191222 seconds, 2.154164 spent in SQL queries.

Feb 14 00:20:08: ...Done Authorize/INVITE in 3.212836 seconds, 3.179098 spent in SQL queries.

Feb 14 00:20:23: ...Done Authorize/INVITE in 4.554871 seconds, 4.524211 spent in SQL queries.

Feb 14 00:20:55: ...Done Authorize/INVITE in 2.341858 seconds, 2.311562 spent in SQL queries.

Feb 14 00:21:04: ...Done Authorize/INVITE in 2.210727 seconds, 2.178325 spent in SQL queries.

Feb 14 00:21:23: ...Done Authorize/INVITE in 6.235502 seconds, 6.218957 spent in SQL queries.

Feb 14 00:21:52: ...Done Authorize/INVITE in 3.048439 seconds, 2.984810 spent in SQL queries.

Feb 14 00:23:46: ...Done Authorize/INVITE in 2.518745 seconds, 2.457082 spent in SQL queries.

Feb 15 00:00:52: ...Done Authorize/INVITE in 6.459876 seconds, 6.443427 spent in SQL queries.

Feb 15 00:03:14: ...Done Authorize/INVITE in 2.370694 seconds, 2.321109 spent in SQL queries.

Feb 15 00:03:28: ...Done Authorize/INVITE in 3.866863 seconds, 3.836249 spent in SQL queries.

Feb 15 00:04:18: ...Done Authorize/INVITE in 2.445715 seconds, 2.374105 spent in SQL queries.

Feb 15 00:05:53: ...Done Authorize/INVITE in 2.056803 seconds, 2.018464 spent in SQL queries.

Feb 15 00:05:59: ...Done Authorize/INVITE in 2.051485 seconds, 2.005998 spent in SQL queries.

Feb 15 00:06:52: ...Done Authorize/INVITE in 2.199050 seconds, 2.159971 spent in SQL queries.

Feb 15 00:24:12: ...Done Authorize/INVITE in 25.879495 seconds, 25.860101 spent in SQL queries.

Feb 15 00:24:45: ...Done Authorize/INVITE in 23.231352 seconds, 23.216225 spent in SQL queries.

Feb 15 00:25:02: ...Done Authorize/INVITE in 6.677252 seconds, 6.619668 spent in SQL queries.

Feb 15 00:25:15: ...Done Authorize/INVITE in 9.440872 seconds, 9.424556 spent in SQL queries.

Feb 15 01:25:49: ...Done Authorize/INVITE in 1.948820 seconds, 1.807061 spent in SQL queries.

Feb 15 01:26:28: ...Done Authorize/INVITE in 1.822758 seconds, 1.806243 spent in SQL queries.

Feb 16 00:00:55: ...Done Authorize/INVITE in 3.755930 seconds, 3.725484 spent in SQL queries.

Feb 16 00:02:25: ...Done Authorize/INVITE in 1.978327 seconds, 1.961876 spent in SQL queries.

Feb 16 00:02:35: ...Done Authorize/INVITE in 7.515030 seconds, 7.498627 spent in SQL queries.

Feb 16 00:03:05: ...Done Authorize/INVITE in 2.351353 seconds, 2.313850 spent in SQL queries.

Feb 16 00:04:17: ...Done Authorize/INVITE in 4.161800 seconds, 4.145551 spent in SQL queries.

Feb 16 00:04:25: ...Done Authorize/INVITE in 5.739072 seconds, 5.726042 spent in SQL queries.

Feb 16 00:04:32: ...Done Authorize/INVITE in 4.991451 seconds, 4.944523 spent in SQL queries.

Feb 16 00:04:39: ...Done Authorize/INVITE in 1.813071 seconds, 1.799876 spent in SQL queries.

Feb 16 00:04:43: ...Done Authorize/INVITE in 2.322348 seconds, 2.306077 spent in SQL queries.

Feb 16 00:04:52: ...Done Authorize/INVITE in 2.407001 seconds, 2.372464 spent in SQL queries.

Feb 16 00:08:20: ...Done Authorize/INVITE in 6.928876 seconds, 6.912485 spent in SQL queries.

Feb 16 00:10:18: ...Done Authorize/INVITE in 1.908485 seconds, 1.867030 spent in SQL queries.

Feb 16 00:17:28: ...Done Authorize/INVITE in 3.592551 seconds, 3.560684 spent in SQL queries.

Feb 16 00:18:19: ...Done Authorize/INVITE in 10.507456 seconds, 10.491070 spent in SQL queries.

Feb 16 00:18:32: ...Done Authorize/INVITE in 11.093115 seconds, 11.079766 spent in SQL queries.

Feb 16 00:18:54: ...Done Authorize/INVITE in 8.053704 seconds, 8.040509 spent in SQL queries.

Feb 16 00:19:28: ...Done Authorize/INVITE in 4.108355 seconds, 4.091735 spent in SQL queries.

Feb 16 00:19:40: ...Done Authorize/INVITE in 3.955616 seconds, 3.925210 spent in SQL queries.

Feb 16 01:12:05: ...Done Authorize/INVITE in 2.313336 seconds, 2.272627 spent in SQL queries.

Feb 16 01:43:41: ...Done Authorize/INVITE in 2.768540 seconds, 2.736605 spent in SQL queries.

Feb 17 00:05:51: ...Done Authorize/INVITE in 15.615399 seconds, 15.545299 spent in SQL queries.

Feb 17 00:06:49: ...Done Authorize/INVITE in 2.449437 seconds, 2.435655 spent in SQL queries.

Feb 17 00:07:13: ...Done Authorize/INVITE in 2.894288 seconds, 2.886193 spent in SQL queries.

Feb 17 00:07:27: ...Done Authorize/INVITE in 3.039998 seconds, 3.031749 spent in SQL queries.

Feb 17 00:24:07: ...Done Authorize/INVITE in 1.840894 seconds, 1.800896 spent in SQL queries.

Feb 17 00:26:06: ...Done Authorize/INVITE in 4.275390 seconds, 4.258922 spent in SQL queries.

Feb 17 01:31:22: ...Done Authorize/INVITE in 1.935051 seconds, 1.904278 spent in SQL queries.

Feb 18 00:02:59: ...Done Authorize/INVITE in 2.468793 seconds, 2.449733 spent in SQL queries.

Feb 18 00:03:57: ...Done Authorize/INVITE in 4.646820 seconds, 4.629782 spent in SQL queries.

Feb 18 00:04:12: ...Done Authorize/INVITE in 2.009675 seconds, 1.965952 spent in SQL queries.

Feb 18 00:05:39: ...Done Authorize/INVITE in 1.870509 seconds, 1.862797 spent in SQL queries.

Feb 18 00:05:45: ...Done Authorize/INVITE in 4.998026 seconds, 4.989540 spent in SQL queries.

Feb 18 00:06:01: ...Done Authorize/INVITE in 3.647687 seconds, 3.629530 spent in SQL queries.

Feb 18 00:06:24: ...Done Authorize/INVITE in 4.796424 seconds, 4.780062 spent in SQL queries.

Feb 18 00:06:27: ...Done Authorize/INVITE in 2.246516 seconds, 2.181739 spent in SQL queries.

Feb 18 00:06:43: ...Done Authorize/INVITE in 3.246679 seconds, 3.230473 spent in SQL queries.

Feb 18 00:08:34: ...Done Authorize/INVITE in 2.322021 seconds, 2.285434 spent in SQL queries.

Feb 18 00:12:24: ...Done Authorize/INVITE in 2.096672 seconds, 2.059115 spent in SQL queries.

Feb 18 00:13:53: ...Done Authorize/INVITE in 2.099346 seconds, 2.063213 spent in SQL queries.

Feb 18 00:21:11: ...Done Authorize/INVITE in 2.235801 seconds, 2.219475 spent in SQL queries.

Feb 18 00:22:01: ...Done Authorize/INVITE in 13.883009 seconds, 13.866529 spent in SQL queries.

Feb 18 00:22:31: ...Done Authorize/INVITE in 19.534126 seconds, 19.520875 spent in SQL queries.

Feb 18 00:22:40: ...Done Authorize/INVITE in 6.874234 seconds, 6.857958 spent in SQL queries.

Feb 18 00:23:02: ...Done Authorize/INVITE in 3.840708 seconds, 3.824201 spent in SQL queries.

Feb 18 00:23:17: ...Done Authorize/INVITE in 6.760730 seconds, 6.744249 spent in SQL queries.

Feb 18 00:23:33: ...Done Authorize/INVITE in 8.228543 seconds, 8.220412 spent in SQL queries.

Feb 19 00:05:08: ...Done Authorize/INVITE in 4.429597 seconds, 4.413339 spent in SQL queries.

Feb 19 00:05:15: ...Done Authorize/INVITE in 4.677043 seconds, 4.646850 spent in SQL queries.

Feb 19 00:09:20: ...Done Authorize/INVITE in 2.242740 seconds, 2.206976 spent in SQL queries.

Feb 19 00:14:22: ...Done Authorize/INVITE in 2.545290 seconds, 2.528837 spent in SQL queries.

Feb 19 00:16:06: ...Done Authorize/INVITE in 2.354358 seconds, 2.277573 spent in SQL queries.

Feb 19 00:17:09: ...Done Authorize/INVITE in 6.731190 seconds, 6.701562 spent in SQL queries.

Feb 19 00:18:24: ...Done Authorize/INVITE in 4.813463 seconds, 4.794966 spent in SQL queries.

Feb 19 00:18:40: ...Done Authorize/INVITE in 4.804654 seconds, 4.788182 spent in SQL queries.

Feb 19 00:19:33: ...Done Authorize/INVITE in 3.977311 seconds, 3.960921 spent in SQL queries.

Feb 19 00:21:09: ...Done Authorize/INVITE in 2.657077 seconds, 2.640837 spent in SQL queries.

Feb 19 00:24:01: ...Done Authorize/INVITE in 3.653641 seconds, 3.637269 spent in SQL queries.

Feb 19 00:24:50: ...Done Authorize/INVITE in 3.952680 seconds, 3.910935 spent in SQL queries.

Feb 19 00:25:35: ...Done Authorize/INVITE in 2.467677 seconds, 2.450205 spent in SQL queries.

Feb 19 00:27:51: ...Done Authorize/INVITE in 2.432797 seconds, 2.400980 spent in SQL queries.

Feb 19 00:28:07: ...Done Authorize/INVITE in 5.305981 seconds, 5.264283 spent in SQL queries.

Feb 19 00:28:52: ...Done Authorize/INVITE in 1.972749 seconds, 1.519622 spent in SQL queries.

Feb 19 00:28:55: ...Done Authorize/INVITE in 2.192345 seconds, 2.160701 spent in SQL queries.

Feb 19 00:29:39: ...Done Authorize/INVITE in 5.946590 seconds, 5.930094 spent in SQL queries.

Feb 19 00:31:46: ...Done Authorize/INVITE in 2.160840 seconds, 2.144354 spent in SQL queries.

Feb 19 00:32:57: ...Done Authorize/INVITE in 3.273540 seconds, 3.233497 spent in SQL queries.

Feb 19 00:33:11: ...Done Authorize/INVITE in 3.903695 seconds, 3.895576 spent in SQL queries.

Feb 19 00:35:20: ...Done Authorize/INVITE in 2.929572 seconds, 2.912458 spent in SQL queries.

Feb 19 00:36:44: ...Done Authorize/INVITE in 2.675334 seconds, 2.633217 spent in SQL queries.

Feb 19 00:41:49: ...Done Authorize/INVITE in 11.331396 seconds, 11.314438 spent in SQL queries.

Feb 19 00:42:41: ...Done Authorize/INVITE in 17.345258 seconds, 17.336998 spent in SQL queries.

Feb 19 00:43:41: ...Done Authorize/INVITE in 3.504447 seconds, 3.385236 spent in SQL queries.

Feb 19 01:30:41: ...Done Authorize/INVITE in 2.121813 seconds, 2.090302 spent in SQL queries.

Feb 19 01:31:45: ...Done Authorize/INVITE in 2.198534 seconds, 2.159443 spent in SQL queries.

Feb 19 03:02:23: ...Done Authorize/INVITE in 2.189755 seconds, 2.151142 spent in SQL queries.

fraud-control:/home/folders/110225-invites#

fraud-control:/home/folders/110225-invites#

[log]

 

Note that the time in the log file is provided in PST, while in the Excel file it is converted in CET time zone.

 

Introduction

 

The following test shows that all logged invite authentication requests are accompanied by a processing time record.

 

fraud-control:/home/var/log/radius#

fraud-control:/home/var/log/radius# cat 110223,090042,201808,0,rotated,radius.log | perl -ne 'if(/^$/ && $a=~/^nas-ip-address.*^h323-conf-id.*method.*invite.*/ism){print $a if($a!~/Done Authorize.INVITE in/)} $a="" if(/^$/); $a.=$_'

fraud-control:/home/var/log/radius#

 

 

The following chart shows the average time spent by the radius server for 5 min intervals.

[zip]

 

All cases of invite requests processed in more than 1 second can be found in the daily log by the following command line:

 

fraud-control:/home/folders/110225-invites#

fraud-control:/home/folders/110225-invites# cat /home/var/log/radius/110224,090046,201790,0,rotated,radius.log | perl -ne 'if(/^([^ ]+ +[0-9]+) +([0-9:]+): \.\.\.Done Authorize\/INVITE in ([0-9.]+) seconds, ([0-9.]+) spent in SQL queries\.$/){$date=$1; $time=$2; $total=$3; $sql=$4; print if($total > 1)}'

Feb 24 00:12:15: ...Done Authorize/INVITE in 1.253967 seconds, 1.221725 spent in SQL queries.

Feb 24 00:12:23: ...Done Authorize/INVITE in 2.785065 seconds, 2.768906 spent in SQL queries.

Feb 24 00:13:13: ...Done Authorize/INVITE in 1.600808 seconds, 1.566315 spent in SQL queries.

Feb 24 00:14:27: ...Done Authorize/INVITE in 1.550839 seconds, 1.519080 spent in SQL queries.

Feb 24 00:14:50: ...Done Authorize/INVITE in 1.953423 seconds, 1.911623 spent in SQL queries.

Feb 24 00:15:11: ...Done Authorize/INVITE in 1.146464 seconds, 1.112943 spent in SQL queries.

Feb 24 00:15:52: ...Done Authorize/INVITE in 8.425980 seconds, 8.409533 spent in SQL queries.

Feb 24 00:16:04: ...Done Authorize/INVITE in 4.615599 seconds, 4.599381 spent in SQL queries.

Feb 24 00:16:46: ...Done Authorize/INVITE in 1.138968 seconds, 1.122514 spent in SQL queries.

Feb 24 00:18:03: ...Done Authorize/INVITE in 1.515901 seconds, 1.478320 spent in SQL queries.

Feb 24 00:19:19: ...Done Authorize/INVITE in 2.760451 seconds, 2.730553 spent in SQL queries.

Feb 24 00:21:27: ...Done Authorize/INVITE in 1.047024 seconds, 1.030418 spent in SQL queries.

Feb 24 00:22:30: ...Done Authorize/INVITE in 1.083549 seconds, 1.049626 spent in SQL queries.

Feb 24 00:23:02: ...Done Authorize/INVITE in 2.237400 seconds, 2.204385 spent in SQL queries.

Feb 24 00:23:33: ...Done Authorize/INVITE in 1.710871 seconds, 1.667733 spent in SQL queries.

Feb 24 00:24:59: ...Done Authorize/INVITE in 1.008390 seconds, 0.967440 spent in SQL queries.

Feb 24 00:28:19: ...Done Authorize/INVITE in 1.080803 seconds, 1.045036 spent in SQL queries.

Feb 24 00:28:53: ...Done Authorize/INVITE in 1.105748 seconds, 1.067983 spent in SQL queries.

Feb 24 00:28:55: ...Done Authorize/INVITE in 1.040234 seconds, 1.010318 spent in SQL queries.

Feb 24 00:31:19: ...Done Authorize/INVITE in 3.415789 seconds, 3.398617 spent in SQL queries.

Feb 24 00:31:34: ...Done Authorize/INVITE in 1.797655 seconds, 1.748269 spent in SQL queries.

Feb 24 00:32:29: ...Done Authorize/INVITE in 1.280192 seconds, 1.247773 spent in SQL queries.

Feb 24 00:32:44: ...Done Authorize/INVITE in 8.806046 seconds, 8.786301 spent in SQL queries.

Feb 24 00:32:48: ...Done Authorize/INVITE in 1.956632 seconds, 1.926202 spent in SQL queries.

Feb 24 00:32:58: ...Done Authorize/INVITE in 2.251668 seconds, 2.241752 spent in SQL queries.

Feb 24 00:33:03: ...Done Authorize/INVITE in 3.341902 seconds, 3.324453 spent in SQL queries.

Feb 24 00:33:22: ...Done Authorize/INVITE in 2.986150 seconds, 2.969194 spent in SQL queries.

Feb 24 00:33:25: ...Done Authorize/INVITE in 1.726571 seconds, 1.713303 spent in SQL queries.

Feb 24 00:36:13: ...Done Authorize/INVITE in 1.084789 seconds, 1.050269 spent in SQL queries.

Feb 24 00:39:28: ...Done Authorize/INVITE in 1.212377 seconds, 1.174518 spent in SQL queries.

Feb 24 01:04:53: ...Done Authorize/INVITE in 1.993001 seconds, 1.976845 spent in SQL queries.

Feb 24 01:06:09: ...Done Authorize/INVITE in 62.381848 seconds, 62.336549 spent in SQL queries.

Feb 24 01:07:49: ...Done Authorize/INVITE in 94.122503 seconds, 94.061494 spent in SQL queries.

Feb 24 01:09:24: ...Done Authorize/INVITE in 73.886387 seconds, 73.864097 spent in SQL queries.

Feb 24 01:09:38: ...Done Authorize/INVITE in 2.222394 seconds, 2.181515 spent in SQL queries.

Feb 24 01:09:41: ...Done Authorize/INVITE in 1.814260 seconds, 1.761632 spent in SQL queries.

Feb 24 01:09:50: ...Done Authorize/INVITE in 3.803457 seconds, 3.786934 spent in SQL queries.

Feb 24 01:10:00: ...Done Authorize/INVITE in 4.162497 seconds, 4.120542 spent in SQL queries.

Feb 24 01:10:05: ...Done Authorize/INVITE in 4.818195 seconds, 4.800860 spent in SQL queries.

Feb 24 01:10:09: ...Done Authorize/INVITE in 2.958490 seconds, 2.945278 spent in SQL queries.

Feb 24 01:10:12: ...Done Authorize/INVITE in 2.290532 seconds, 2.266177 spent in SQL queries.

Feb 24 01:10:16: ...Done Authorize/INVITE in 2.481977 seconds, 2.468695 spent in SQL queries.

Feb 24 01:10:22: ...Done Authorize/INVITE in 4.754724 seconds, 4.741225 spent in SQL queries.

Feb 24 01:10:28: ...Done Authorize/INVITE in 4.851553 seconds, 4.835030 spent in SQL queries.

Feb 24 01:10:36: ...Done Authorize/INVITE in 5.608283 seconds, 5.594937 spent in SQL queries.

Feb 24 01:10:50: ...Done Authorize/INVITE in 5.596401 seconds, 5.580081 spent in SQL queries.

Feb 24 01:10:54: ...Done Authorize/INVITE in 3.993838 seconds, 3.977432 spent in SQL queries.

Feb 24 01:11:02: ...Done Authorize/INVITE in 6.931499 seconds, 6.900159 spent in SQL queries.

Feb 24 01:11:18: ...Done Authorize/INVITE in 1.628830 seconds, 1.592562 spent in SQL queries.

Feb 24 01:11:26: ...Done Authorize/INVITE in 1.279309 seconds, 1.248036 spent in SQL queries.

Feb 24 01:12:44: ...Done Authorize/INVITE in 1.068600 seconds, 0.980695 spent in SQL queries.

Feb 24 01:16:02: ...Done Authorize/INVITE in 1.010367 seconds, 0.963615 spent in SQL queries.

Feb 24 01:17:44: ...Done Authorize/INVITE in 1.509664 seconds, 1.468229 spent in SQL queries.

Feb 24 01:26:07: ...Done Authorize/INVITE in 1.883488 seconds, 1.640538 spent in SQL queries.

Feb 24 01:30:04: ...Done Authorize/INVITE in 1.078043 seconds, 1.045644 spent in SQL queries.

Feb 24 01:39:05: ...Done Authorize/INVITE in 2.329061 seconds, 2.293553 spent in SQL queries.

Feb 24 02:33:19: ...Done Authorize/INVITE in 1.079715 seconds, 1.037711 spent in SQL queries.

Feb 24 03:16:02: ...Done Authorize/INVITE in 1.063701 seconds, 1.022343 spent in SQL queries.

Feb 24 03:58:19: ...Done Authorize/INVITE in 1.398892 seconds, 1.357403 spent in SQL queries.

Feb 24 05:07:29: ...Done Authorize/INVITE in 1.049232 seconds, 1.010388 spent in SQL queries.

Feb 24 05:43:24: ...Done Authorize/INVITE in 1.014165 seconds, 0.973242 spent in SQL queries.

Feb 24 14:08:33: ...Done Authorize/INVITE in 1.908850 seconds, 1.877987 spent in SQL queries.

Feb 24 22:33:50: ...Done Authorize/INVITE in 1.552998 seconds, 1.528639 spent in SQL queries.

Feb 24 23:25:30: ...Done Authorize/INVITE in 1.019601 seconds, 0.968896 spent in SQL queries.

Feb 24 23:57:19: ...Done Authorize/INVITE in 3.290312 seconds, 3.260030 spent in SQL queries.

fraud-control:/home/folders/110225-invites#

fraud-control:/home/folders/110225-invites#

[log]

 

Note that the time in the log is in the US Pacific Time Zone while the time in the Excel chart is converted into CET Swiss time.

 

The morning peaks are systematic. During these peaks, the SIP nodes are processing the calls with serious delays with many calls dropped. At the same time the CPU load on SIP servers increases significantly, which is a known problem.

The solution, being currently studied, is to equip the SIP servers with intelligence permitting them to route the calls autonomously.

 

 

References

 

Radius server processing time of the invite authorization requests (this page):

http://switzernet.com/3/public/110225-radius-invite/

http://unappel.ch/2/public/110225-radius-invite/

http://parinternet.ch/2/public/110225-radius-invite/

 

Recreation of calls from radius log files:

http://switzernet.com/3/public/110222-radius-log-cdr/

http://unappel.ch/2/public/110222-radius-log-cdr/

http://parinternet.ch/2/public/110222-radius-log-cdr/

 

Synchronization and backup of the rotating radius log file:

http://switzernet.com/3/public/101228-radius-log/

http://unappel.ch/2/public/101228-radius-log/

http://parinternet.ch/2/public/101228-radius-log/

 

CPU load of SIP servers:

http://unappel.ch/public/080210-ser-cpu/

http://intarnet.com/2/public/100617-ser-cpu/

http://parinternet.ch/2/public/100617-ser-cpu/

http://switzernet.com/2/public/100617-ser-cpu/

 

 

Copyright © 2011 switzernet.com

*   *   *