Hello…
I tracked down a bug fix for that problem (issues.asterisk.org/view.php?id=4418 - Digium Issue 4418) which seems to be solved back in 2005… But in my case is still happening… Below is a prtion of the Log file where cleraly we can see that after the Attended transfer the target phone is placed on Hold and Music on Hold starts playing…
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: **** Received REFER (9) - Command in SIP REFER
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: Attended transfer: Will use Replace-Call-ID : 0055c66ccb3e4f2a@192.168.0.213 (No check of from/to tags)
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: Looking for callid 0055c66ccb3e4f2a@192.168.0.213 (fromtag bea7849c3a4e1657 totag as69afd50c)
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: Matched INCOMING call - their tag is bea7849c3a4e1657 Our tag is as69afd50c
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: Sip transfer:--------------------
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: – Transferer to PBX channel: SIP/304-0a109ff0 State Up
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: – Transferer to PBX second channel (target): SIP/304-b6115770 State Up
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: – Bridged call to transferee: Local/304@from-internal-db2c,2 State Up
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: – Bridged call to transfer target: SIP/203-0a1b2058 State Up
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: – END Sip transfer:--------------------
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: SIP transfer: Four channels to handle
[2009-05-27 10:08:56] VERBOSE[3958] logger.c: – Stopped music on hold on Local/304@from-internal-db2c,2
[2009-05-27 10:08:56] DEBUG[3958] channel.c: Set channel Local/304@from-internal-db2c,2 to write format alaw
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: SIP transfer: trying to masquerade Local/304@from-internal-db2c,2 into SIP/304-b6115770
[2009-05-27 10:08:56] DEBUG[3958] channel.c: Planning to masquerade channel Local/304@from-internal-db2c,2 into the structure of SIP/304-b6115770
[2009-05-27 10:08:56] DEBUG[3958] channel.c: Done planning to masquerade channel Local/304@from-internal-db2c,2 into the structure of SIP/304-b6115770
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: SIP transfer: Succeeded to masquerade channels.
[2009-05-27 10:08:56] DEBUG[3958] chan_sip.c: SIP attended transfer: Unlocking channel SIP/304-b6115770
[2009-05-27 10:08:56] DEBUG[8523] res_musiconhold.c: SIP/203-0a1b2058 Opened file 0 ‘/var/lib/asterisk/mohmp3//wav_1846_suppe_-poet_and_peasant-_overture’
[2009-05-27 10:08:56] DEBUG[8523] channel.c: Actually Masquerading Local/304@from-internal-db2c,2(6) into the structure of SIP/304-b6115770(6)
[2009-05-27 10:08:56] DEBUG[8523] channel.c: Got clone lock for masquerade on ‘Local/304@from-internal-db2c,2’ at 0xa13c398
[2009-05-27 10:08:56] DEBUG[8523] chan_sip.c: SIP Fixup: New owner for dialogue 0055c66ccb3e4f2a@192.168.0.213: Local/304@from-internal-db2c,2 (Old parent: Local/304@from-internal-db2c,2)
[2009-05-27 10:08:56] DEBUG[8523] chan_sip.c: Hangup call Local/304@from-internal-db2c,2, SIP callid 0055c66ccb3e4f2a@192.168.0.213)
[2009-05-27 10:08:56] DEBUG[8523] chan_sip.c: Updating call counter for incoming call
[2009-05-27 10:08:56] DEBUG[8523] devicestate.c: Notification of state change to be queued on device/channel SIP/304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: No provider found, checking channel drivers for SIP - 304
[2009-05-27 10:08:56] DEBUG[3921] chan_sip.c: Checking device state for peer 304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Changing state for SIP/304 - state 8 (On Hold)
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: No provider found, checking channel drivers for SIP - 304
[2009-05-27 10:08:56] DEBUG[3921] chan_sip.c: Checking device state for peer 304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking if I can find provider for “Custom” - number: DND304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking provider SLA with Custom
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking provider Meetme with Custom
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking provider Custom with Custom
[2009-05-27 10:08:56] DEBUG[3921] db.c: Unable to find key ‘DND304’ in family ‘CustomDevstate’
[2009-05-27 10:08:56] DEBUG[3939] app_queue.c: Device ‘SIP/304’ changed to state ‘8’ (On Hold) but we don’t care because they’re not a member of any queue.
[2009-05-27 10:08:56] DEBUG[8523] chan_sip.c: Call from peer ‘304’ removed from call limit 50
[2009-05-27 10:08:56] DEBUG[8523] devicestate.c: Notification of state change to be queued on device/channel SIP/304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: No provider found, checking channel drivers for SIP - 304
[2009-05-27 10:08:56] DEBUG[3921] chan_sip.c: Checking device state for peer 304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Changing state for SIP/304 - state 8 (On Hold)
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: No provider found, checking channel drivers for SIP - 304
[2009-05-27 10:08:56] DEBUG[3921] chan_sip.c: Checking device state for peer 304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking if I can find provider for “Custom” - number: DND304
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking provider SLA with Custom
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking provider Meetme with Custom
[2009-05-27 10:08:56] DEBUG[3921] devicestate.c: Checking provider Custom with Custom
[2009-05-27 10:08:56] DEBUG[3921] db.c: Unable to find key ‘DND304’ in family ‘CustomDevstate’
[2009-05-27 10:08:56] DEBUG[3939] app_queue.c: Device ‘SIP/304’ changed to state ‘8’ (On Hold) but we don’t care because they’re not a member of any queue.
[2009-05-27 10:08:56] DEBUG[8523] channel.c: Putting channel Local/304@from-internal-db2c,2 in 8/8 formats
[2009-05-27 10:08:56] DEBUG[8523] channel.c: Released clone lock on ‘SIP/304-b6115770’
[2009-05-27 10:08:56] DEBUG[8523] channel.c: Done Masquerading Local/304@from-internal-db2c,2 (6)
[2009-05-27 10:08:56] DEBUG[8525] audiohook.c: Read factory 0xa135908 was pretty quick last time, waiting for them.
[2009-05-27 10:08:56] DEBUG[8447] channel.c: Didn’t get a frame from channel: SIP/304-b6115770
[2009-05-27 10:08:56] DEBUG[8447] channel.c: Bridge stops bridging channels SIP/304-b6115770 and SIP/304-0a109ff0
[2009-05-27 10:08:56] DEBUG[8447] channel.c: Hanging up channel ‘SIP/304-0a109ff0’
[2009-05-27 10:08:56] DEBUG[8447] chan_sip.c: Updating call counter for outgoing call
[2009-05-27 10:08:56] DEBUG[8447] devicestate.c: Notification of state change to be queued on device/channel SIP/304
[2009-05-27 10:08:56] DEBUG[8447] chan_sip.c: Call to peer ‘304’ removed from call limit 50
[2009-05-27 10:08:56] DEBUG[8447] devicestate.c: Notification of state change to be queued on device/channel SIP/304
[2009-05-27 10:08:56] DEBUG[8447] chan_sip.c: SIP Transfer: Not hanging up right now… Rescheduling hangup for 6cdc8cf97233da7f5db9b8e639cc9eba@192.168.0.200.
[2009-05-27 10:08:56] DEBUG[8447] devicestate.c: Notification of state change to be queued on device/channel SIP/304-0a109ff0
[2009-05-27 10:08:56] DEBUG[8447] devicestate.c: Notification of state change to be queued on device/channel SIP/304
[2009-05-27 10:08:56] DEBUG[8447] rtp.c: Channel ‘’ has no RTP, not doing anything
[2009-05-27 10:08:56] DEBUG[8447] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[2009-05-27 10:08:56] DEBUG[8447] app_macro.c: Spawn extension (macro-dial,s,7) exited non-zero on ‘SIP/304-b6115770’ in macro ‘dial’
[2009-05-27 10:08:56] DEBUG[8447] app_macro.c: Spawn extension (macro-dial,s,7) exited non-zero on ‘SIP/304-b6115770’ in macro ‘exten-vm’
[2009-05-27 10:08:56] DEBUG[8447] pbx.c: Spawn extension (macro-dial,s,7) exited non-zero on ‘SIP/304-b6115770’
[2009-05-27 10:08:56] VERBOSE[8447] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/304-b6115770’
[2009-05-27 10:08:56] DEBUG[8447] channel.c: Soft-Hanging up channel ‘SIP/304-b6115770’
I can’t see a reason why it happens or the causes that make it happen…
We use Grandstream GXP280 and 2000… And Asterisk 1.4.21.2 through PiaF distro…
Thank you for your help in advance…