dial level problem

All installation and configuration problems and questions

Moderators: gerski, enjay, williamconley, Op3r, Staydog, gardo, mflorell, MJCoate, mcargile, Kumba, Michael_N

dial level problem

Postby aster1 » Fri Mar 16, 2007 1:58 pm

I have got this strange problems in one of my production servers since last few days . Vicidial is not respecting the dial level i set to it . See the 2 screenshots below . If i set dial level to 4.0 in ratio mode it is just making 10 calls . If max level is set to 7.0 in adapt_hard_limit mode still it makes 25 calls for 6 agents where it should make 42 atleast . Theres no other problem everythin is working perfectly , server load is very low .

campaign settings are:
available only tally=N
max adapt dial 7.0
dial timeout 25 secs
all calls recorded
campaign vdad extension 8369

screen -r:
There are several suitable screens on:
3156.ASTupdate (Detached)
3159.ASTsend (Detached)
3162.ASTlisten (Detached)
3165.ASTVDauto (Detached)
3167.ASTVDremote (Detached)
3171.ASTVDadapt (Detached)
3174.ASTfastlog (Detached)
Type "screen [-d] -r [pid.]tty.host" to resume one of them.




Image
Image
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby aster1 » Fri Mar 16, 2007 2:01 pm

also drop % is set to 10% in campaign . this happens almost everyday now and works fine on server restart ( ast_var_mysql cleanup script is set to run on every restart .
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby mflorell » Fri Mar 16, 2007 8:35 pm

Can you attach to the ASTVDauto screen and post some output when this happens?
mflorell
Site Admin
 
Posts: 18334
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby aster1 » Sun Mar 18, 2007 2:17 am

its sunday today . will attach o/p tmrw :)
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby dfwonsite » Sun Mar 18, 2007 2:30 pm

having a weird problem here, too... but i'm pretty new to vici so could be something i just haven't fully understood...

in all auto dial methods, the calls to place are showing up as a negative number after working fine yesterday....


loop counter: |5759999|
TIME DEBUG: -5|-4|1| GMT: 18:29
2007-03-18 14:29:04|LIVE AGENTS LOGGED IN: 1|
2007-03-18 14:29:04|111 192.168.1.143: agents: 1 dial_level: 4.0|
2007-03-18 14:29:04|111 192.168.1.143: Calls to place: -8 (4 - 12) |
2007-03-18 14:29:04|CAMPAIGN DIFFERENTIAL: 1 1 (1 - 0)|
2007-03-18 14:29:04|LOCAL TRUNK SHORTAGE: 0|0 (4 - 96)|
2007-03-18 14:29:04|111 192.168.1.143: CALLING|
TIME DEBUG: -5|-4|1| GMT: 18:29
2007-03-18 14:29:04|| lagged call vla agent PAUSED 0E0|20070318142834|20070318142854|20070318142904||
2007-03-18 14:29:04|| lagged call vac agent DELETED 0E0|2007-03-18 14:27:04||
2007-03-18 14:29:04|| lagged call vdac call DELETED 0E0|20070318142854||
dfwonsite
 
Posts: 9
Joined: Sun Mar 18, 2007 12:08 pm

Postby mflorell » Sun Mar 18, 2007 9:21 pm

Check that you have nothing in the vicidial_auto_calls MySQL table before you have agents log in. Also, check that you have call_log entries in all of the places they are supposed to be in extensions.conf.
mflorell
Site Admin
 
Posts: 18334
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby aster1 » Mon Mar 19, 2007 2:43 pm

heres output of screen . it shows 49 calls but dialing only 25-30 calls max


Code: Select all
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
2007-03-20 01:12:24|LIVE AGENTS LOGGED IN: 7|
2007-03-20 01:12:24|001 127.0.0.1: agents: 7     dial_level: 7.0|
2007-03-20 01:12:24|001 127.0.0.1: Calls to place: 1 (49 - 48) |
2007-03-20 01:12:24|CAMPAIGN DIFFERENTIAL: 7   4.45   (4.45 - 0)|
2007-03-20 01:12:24|LOCAL TRUNK SHORTAGE: 0|0  (49 - 96)|
2007-03-20 01:12:24|001 127.0.0.1: CALLING|
|UPDATE vicidial_hopper set status='QUEUE', user='VDAD_127.0.0.1' where campaign_id='001' and status='READY' order by hopper_id LIMIT 1|
hopper rows updated to QUEUE: |1|
|SELECT lead_id FROM vicidial_hopper where campaign_id='001' and status='QUEUE' and user='VDAD_127.0.0.1' LIMIT 1|
|UPDATE vicidial_hopper set status='INCALL' where lead_id='25497'|
hopper row updated to INCALL: |1|25497|
2007-03-20 01:12:24||     number call dialed|001|V0320011224000025497|INSERT INT
O vicidial_manager values('','','2007-03-20 01:12:24','NEW','N','127.0.0.1','','
Originate','V0320011224000025497','Exten: 8369','Context: default','Channel: Loc
al/16617218161@default','Priority: 1','Callerid: "V0320011224000025497" <8888263215>','Timeout: 41000','','','','')|-7.00||
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
2007-03-20 01:12:24||     dead call vac deleted|||V0320011214000025488|1174333344|0E0|||
DBD::mysql::db do failed: Duplicate entry '1174333334.7678001' for key 1 at /usr/share/astguiclient/AST_VDauto_dial.pl line 873.
2007-03-20 01:12:24||     dead NA call added to log 1174333334.7678001||||NA|||
2007-03-20 01:12:24||     dead call vac lead marked NA|||||
2007-03-20 01:12:24||     dead call vla agent PAUSED 0E0|||||
2007-03-20 01:12:24||     lagged call vla agent PAUSED 0E0|20070320011154|20070320011214|20070320011224||
2007-03-20 01:12:24||     lagged call vac agent DELETED 0E0|2007-03-20 01:10:24||
2007-03-20 01:12:24||     lagged call vdac call DELETED 0E0|20070320011214||

loop counter: |5757791|
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
2007-03-20 01:12:27|LIVE AGENTS LOGGED IN: 7|
2007-03-20 01:12:27|001 127.0.0.1: agents: 7     dial_level: 7.0|
2007-03-20 01:12:27|001 127.0.0.1: Calls to place: 1 (49 - 48) |
2007-03-20 01:12:27|CAMPAIGN DIFFERENTIAL: 7   4.55   (4.55 - 0)|
2007-03-20 01:12:27|LOCAL TRUNK SHORTAGE: 0|0  (49 - 96)|
2007-03-20 01:12:27|001 127.0.0.1: CALLING|
|UPDATE vicidial_hopper set status='QUEUE', user='VDAD_127.0.0.1' where campaign_id='001' and status='READY' order by hopper_id LIMIT 1|
hopper rows updated to QUEUE: |1|
|SELECT lead_id FROM vicidial_hopper where campaign_id='001' and status='QUEUE' and user='VDAD_127.0.0.1' LIMIT 1|
|UPDATE vicidial_hopper set status='INCALL' where lead_id='25500'|
hopper row updated to INCALL: |1|25500|
2007-03-20 01:12:27||     number call dialed|001|V0320011227000025500|INSERT INT
O vicidial_manager values('','','2007-03-20 01:12:27','NEW','N','127.0.0.1','','
Originate','V0320011227000025500','Exten: 8369','Context: default','Channel: Loc
al/17602515708@default','Priority: 1','Callerid: "V0320011227000025500" <8888263215>','Timeout: 41000','','','','')|-7.00||
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
2007-03-20 01:12:27||     lagged call vla agent PAUSED 0E0|20070320011157|20070320011217|20070320011227||
2007-03-20 01:12:27||     lagged call vac agent DELETED 0E0|2007-03-20 01:10:27||
2007-03-20 01:12:27||     lagged call vdac call DELETED 0E0|20070320011217||

loop counter: |5757790|
2007-03-20 01:12:27||     lagged call vac agent DELETED 0E0|2007-03-20 01:02:27|LIVE||
2007-03-20 01:12:27||     updating server parameters 96|8365|5.50|default||
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
checking to see if listener is dead |1|
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
2007-03-20 01:12:30|LIVE AGENTS LOGGED IN: 7|
2007-03-20 01:12:30|001 127.0.0.1: agents: 7     dial_level: 7.0|
2007-03-20 01:12:30|001 127.0.0.1: Calls to place: 0 (49 - 49) |
2007-03-20 01:12:30|CAMPAIGN DIFFERENTIAL: 7   4.65   (4.65 - 0)|
2007-03-20 01:12:30|LOCAL TRUNK SHORTAGE: 0|0  (49 - 96)|
2007-03-20 01:12:30|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 19:42
2007-03-20 01:12:30||     lagged call vla agent PAUSED 0E0|20070320011200|20070320011220|20070320011230||
2007-03-20 01:12:30||     lagged call vac agent DELETED 1|2007-03-20 01:10:30||
2007-03-20 01:12:30||     lagged call vdac call DELETED 0E0|20070320011220||

aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby aster1 » Mon Mar 19, 2007 4:17 pm

heres problem again . 7 agent login no calls going screen shows 0 calls now

Code: Select all
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:00||     lagged call vla agent PAUSED 0E0|20070320024330|20070320024350|20070320024400||
2007-03-20 02:44:00||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:00||
2007-03-20 02:44:00||     lagged call vdac call DELETED 0E0|20070320024350||

loop counter: |5757895|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:02|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:02|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:02|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:02|CAMPAIGN DIFFERENTIAL: 3.9   3.15   (3.15 - 0)|
2007-03-20 02:44:02|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:02|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:02||     lagged call vla agent PAUSED 0E0|20070320024332|20070320024352|20070320024402||
2007-03-20 02:44:02||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:02||
2007-03-20 02:44:02||     lagged call vdac call DELETED 0E0|20070320024352||

loop counter: |5757894|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:05|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:05|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:05|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:05|CAMPAIGN DIFFERENTIAL: 3.95   3.2   (3.2 - 0)|
2007-03-20 02:44:05|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:05|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:05||     lagged call vla agent PAUSED 0E0|20070320024335|20070320024355|20070320024405||
2007-03-20 02:44:05||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:05||
2007-03-20 02:44:05||     lagged call vdac call DELETED 0E0|20070320024355||

loop counter: |5757893|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:07|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:07|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:07|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:07|CAMPAIGN DIFFERENTIAL: 4   3.25   (3.25 - 0)|
2007-03-20 02:44:07|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:07|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:07||     lagged call vla agent PAUSED 0E0|20070320024337|20070320024357|20070320024407||
2007-03-20 02:44:07||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:07||
2007-03-20 02:44:07||     lagged call vdac call DELETED 0E0|20070320024357||

loop counter: |5757892|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:10|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:10|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:10|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:10|CAMPAIGN DIFFERENTIAL: 4   3.3   (3.3 - 0)|
2007-03-20 02:44:10|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:10|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:10||     lagged call vla agent PAUSED 0E0|20070320024340|20070320024400|20070320024410||
2007-03-20 02:44:10||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:10||
2007-03-20 02:44:10||     lagged call vdac call DELETED 0E0|20070320024400||

loop counter: |5757891|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:12|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:12|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:12|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:12|CAMPAIGN DIFFERENTIAL: 4   3.35   (3.35 - 0)|
2007-03-20 02:44:12|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:12|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:12||     lagged call vla agent PAUSED 0E0|20070320024342|20070320024402|20070320024412||
2007-03-20 02:44:12||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:12||
2007-03-20 02:44:12||     lagged call vdac call DELETED 0E0|20070320024402||

loop counter: |5757890|
2007-03-20 02:44:12||     lagged call vac agent DELETED 0E0|2007-03-20 02:34:12|LIVE||
2007-03-20 02:44:12||     updating server parameters 96|8365|5.50|default||
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
checking to see if listener is dead |1|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:15|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:15|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:15|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:15|CAMPAIGN DIFFERENTIAL: 4   3.4   (3.4 - 0)|
2007-03-20 02:44:15|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:15|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:15||     lagged call vla agent PAUSED 0E0|20070320024345|20070320024405|20070320024415||
2007-03-20 02:44:15||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:15||
2007-03-20 02:44:15||     lagged call vdac call DELETED 0E0|20070320024405||

loop counter: |5757889|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:17|LIVE AGENTS LOGGED IN: 3|
2007-03-20 02:44:17|001 127.0.0.1: agents: 3     dial_level: 2.5|
2007-03-20 02:44:17|001 127.0.0.1: Calls to place: -23 (8 - 31) |
2007-03-20 02:44:17|CAMPAIGN DIFFERENTIAL: 4   3.45   (3.45 - 0)|
2007-03-20 02:44:17|LOCAL TRUNK SHORTAGE: 0|0  (8 - 96)|
2007-03-20 02:44:17|001 127.0.0.1: CALLING|
TIME DEBUG: 5.50|5.50|0|   GMT: 21:14
2007-03-20 02:44:17||     lagged call vla agent PAUSED 0E0|20070320024347|20070320024407|20070320024417||
2007-03-20 02:44:17||     lagged call vac agent DELETED 0E0|2007-03-20 02:42:17||
2007-03-20 02:44:17||     lagged call vdac call DELETED 0E0|20070320024407||

aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby mflorell » Mon Mar 19, 2007 4:30 pm

do you have more than one server? or separate dialer and database/web servers?
mflorell
Site Admin
 
Posts: 18334
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby aster1 » Mon Mar 19, 2007 4:34 pm

nop all on same dual core server and loasd is also less than 1 most of time
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby mflorell » Mon Mar 19, 2007 11:32 pm

Check the phone numbers that are stuck in the vicidial_auto_calls table and see if they are dialable in your dialplan.

Also, check that you have call_log AGI entries in your h, 91NXXNXXXXXX, 8365 extensions in your dialplan.
mflorell
Site Admin
 
Posts: 18334
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby aster1 » Tue Mar 20, 2007 12:28 pm

i emptied that table and it seems to work for now . I have call_log entries everywhere um sure of it . Its working fine for now . I will see few more days and letr u know if its completely resolved :) . does admin_var_mysql.pl script clean that table ?
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby aster1 » Tue Mar 20, 2007 1:09 pm

just saw ths in cli .


Mar 20 23:37:45 NOTICE[10881]: chan_local.c:523 local_alloc: No such extension/context XXYYXXYYXXYYXX48600058@default creating local channel
Mar 20 23:37:45 NOTICE[10881]: channel.c:2490 __ast_request_and_dial: Unable to request channel Local/XXYYXXYYXXYYXX48600058@default
Mar 20 23:37:45 NOTICE[10891]: chan_local.c:523 local_alloc: No such extension/context XXYYXXYYXXYYXX48600058@default creating local channel
Mar 20 23:37:45 NOTICE[10891]: channel.c:2490 __ast_request_and_dial: Unable to request channel Local/XXYYXXYYXXYYXX48600058@default
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby mflorell » Tue Mar 20, 2007 4:14 pm

Looks like one of your agents is trying to raise and lower volume.

Make sure you have at least 2.0.2 scripts loaded(including the manager_send and send_child scripts), make sure you applied the volume control patch before you compiled Asterisk, and make sure you have the following lines in your extensions.conf:

Code: Select all
exten => _X48600XXX,1,MeetMeAdmin(${EXTEN:2},T,${EXTEN:0:1})
exten => _X48600XXX,2,Hangup

exten => _X38600XXX,1,MeetMeAdmin(${EXTEN:2},t,${EXTEN:0:1})
exten => _X38600XXX,2,Hangup

exten => _X28600XXX,1,MeetMeAdmin(${EXTEN:2},m,${EXTEN:0:1})
exten => _X28600XXX,2,Hangup

exten => _X18600XXX,1,MeetMeAdmin(${EXTEN:2},M,${EXTEN:0:1})
exten => _X18600XXX,2,Hangup

exten => _55558600XXX,1,MeetMeAdmin(${EXTEN:4},K)
exten => _55558600XXX,2,Hangup
exten => 8300,1,Hangup


mflorell
Site Admin
 
Posts: 18334
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby aster1 » Tue Mar 20, 2007 4:53 pm

Thanx Matt .i did had that in dialplan . My calling problem is solved .. it was due to old records sitting in vicidial_auto_calls creating this problem . mysql cleaning script does solve this problem . I think some cron script should check for entries older than 2 hour in that table and delete it . I keep the AST_reset_mysql_vars.pl in startup that fixes on reboot .

any idea on this one ? Its iax provider trunk

WARNING[27843]: channel.c:781 channel_find_locked: Avoided initial deadlock for '0x834d7c8', 10 retries!

i am getting lot of this in cli .
aster1
 
Posts: 281
Joined: Sun Dec 24, 2006 6:48 am
Location: India

Postby mflorell » Tue Mar 20, 2007 8:07 pm

I see that "Avoided initial deadlock" a lot when doing too much recording on a loaded server, or when trying to push too many IAX channels through a small internet connection.
mflorell
Site Admin
 
Posts: 18334
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida


Return to Support

Who is online

Users browsing this forum: Majestic-12 [Bot] and 48 guests