[asterisk-bugs] [Asterisk 0016081]: utils.c:938 ast_carefulwrite: Timed out trying to write causes corruption to astdb

[Asterisk Bug Tracker]

A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=16081 
====================================================================== 
Reported By:                aragon
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   16081
Category:                   Applications/app_queue
Reproducibility:            have not tried
Severity:                   block
Priority:                   normal
Status:                     new
Asterisk Version:           1.4.26.1 
JIRA:                        
Regression:                 No 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2009-10-15 10:02 CDT
Last Modified:              2009-10-16 09:05 CDT
====================================================================== 
Summary:                    utils.c:938 ast_carefulwrite: Timed out trying to
write causes corruption to astdb
Description: 
Agent addmember to local extensions causes the agent to be logged as
non-existent channels when ast_carefulwrite times out during login.

[Oct 15 10:40:07] NOTICE[29962]: utils.c:938 ast_carefulwrite: Timed out
trying to write
[Oct 15 10:40:07] NOTICE[29962]: utils.c:938 ast_carefulwrite: Timed out
trying to write

Here  is an example of the corruption where the same local extension is
logged twice.  The "outgoing" agent cannot logoff unless I manually remove
from astdb.  The local agent can logoff but since the outgoing cannot calls
entering queue fail to reach agents and the local channel cannot log back
in.

Local/3345 at queuefifteen-outgoing/n (dynamic) (Invalid) has taken no calls
yet
      Local/3345 at queuefifteen-agent/n (dynamic) (Not in use) has taken 2
calls (last was                                                            
    1915 secs ago)

====================================================================== 

---------------------------------------------------------------------- 
 (0112363) aragon (reporter) - 2009-10-16 09:05
 https://issues.asterisk.org/view.php?id=16081#c112363 
---------------------------------------------------------------------- 
I didn't set the category correctly.
This bug effects IVR and queues and appears to fall under AGI.

Debug info uploaded as 16081agi_debug_16102009.txt

I reproduced the carefulwrite notices by calling into the PRI span and the
accepted on Zap 49.

The interesting bit in the log prior to the carewrite notice is this:

    -- Accepting call from '5555551234' to '4350' on channel 0/1, span 3
[Oct 16 09:27:28] DEBUG[21737]: chan_dahdi.c:1784 dahdi_enable_ec: Enabled
echo cancellation on channel 49
[Oct 16 09:27:28] DEBUG[27764]: manager.c:2233 process_message: Manager
received command 'Ping'
[Oct 16 09:27:28] DEBUG[11247]: pbx.c:1843 pbx_extension_helper: Launching
'Answer'
    -- Executing [4350 at zap-incoming:1] Answer("Zap/49-1", "") in new
stack
[Oct 16 09:27:28] DEBUG[27764]: manager.c:2233 process_message: Manager
received command 'Command'
[Oct 16 09:27:28] DEBUG[11247]: devicestate.c:302
ast_device_state_changed_literal: Notification of state change to be queued
on device/channel Zap/49
[Oct 16 09:27:28] DEBUG[21730]: channel.c:1133 channel_find_locked:
Avoiding initial deadlock for channel '0x9750fa8'
[Oct 16 09:27:28] DEBUG[21730]: channel.c:1133 channel_find_locked:
Avoiding initial deadlock for channel '0x9750fa8'
[Oct 16 09:27:28] DEBUG[11247]: chan_dahdi.c:5474 dahdi_indicate:
Requested indication -1 on channel Zap/49-1
[Oct 16 09:27:28] DEBUG[21730]: channel.c:1133 channel_find_locked:
Avoiding initial deadlock for channel '0x9750fa8'
[Oct 16 09:27:28] DEBUG[11247]: pbx.c:1843 pbx_extension_helper: Launching
'Set'
    -- Executing [4350 at zap-incoming:2] Set("Zap/49-1",
"CHANNEL(musicclass)=default") in new stack
[Oct 16 09:27:28] DEBUG[21730]: devicestate.c:287 do_state_change:
Changing state for Zap/49 - state 2 (In use)
[Oct 16 09:27:28] DEBUG[21779]: app_queue.c:682 handle_statechange: Device
'Zap/49' changed to state '2' (In use) but we don't care because they're
not a member of any queue. 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-10-16 09:05 aragon         Note Added: 0112363                          
======================================================================