[Freeswitch-dev] SIP fantom calls, when calling disconnected SIP endpoint. EP called when plugged in. suppose bug?

[Anton VG]

While emulating end-user behavior, encountered a problem. When there
is a call to the SIP endpoint, which have disappeared (power
unplugged), SOFIA queues the call and calls that endpoint, if it's
plugged IN back, within
origination_timeout interval. So it means, that there is NO job UUID
(I kill all job uuid's by UUID_kill, no show calls, no show channels.
But still - I do plug my phone back, it registers to FS, and in 10
seconds I'm receiving a call to it!

Reproducibility 100%

How to reproduce:

Register an endpoint.
Unplug the power, so registration persists in FS
I do 'originate' a call to a SIP endpoint and &park as shown

originate {ringback='%(2000,4000,440.0,480.0)',origination_caller_id_number=907388397,originate_timeout=60,origination_uuid=f84558f4-46e9-4f8a-a546-7edfd6fd0d5e,leg_timeout=60}[continue_on_fail=false,leg_a_uuid=bb744c31-92cf-47d1-aaeb-1c984cb4d599]sofia/internal/sip:sip3779100 at 192.168.5.21:5062;fs_nat=yes;fs_path=sip%3Asip3779100%40192.168.5.21%3A5062
&park

than System attempts to call that endpoint, wait for 4 seconds,
disconnect. Kill all job UUIDs, which was originating the call.

than plug in the phone, and in 10 seconds there is an incoming call.

Just discovered:
If i do not kill the JOB UUIDs - than, when phantom call happens, I
can see the debug:

2011-05-19 19:59:56.662932 [WARNING] sofia_reg.c:1241 SIP auth
challenge (REGISTER) on sofia profile 'internal' for
[sip3779100 at 192.168.100.11] from ip 192.168.5.21
2011-05-19 20:00:08.182927 [INFO] sofia.c:748
sofia/internal/sip:sip3779100 at 192.168.5.21:5062 Update Callee ID to
"Outbound Call" <sip3779100>
2011-05-19 20:00:08.252929 [DEBUG] sofia.c:4770 Channel
sofia/internal/sip:sip3779100 at 192.168.5.21:5062 entering state
[proceeding][180]
2011-05-19 20:00:08.252929 [NOTICE] sofia.c:4848 Ring-Ready
sofia/internal/sip:sip3779100 at 192.168.5.21:5062!
2011-05-19 20:04:24.822927 [DEBUG] switch_channel.c:2592
(sofia/internal/sip:sip3779100 at 192.168.5.21:5062) Callstate Change
RINGING -> HANGUP
2011-05-19 20:04:24.822927 [NOTICE] mod_commands.c:2117 Hangup
sofia/internal/sip:sip3779100 at 192.168.5.21:5062 [CS_CONSUME_MEDIA]
[NORMAL_CLEARING]
2011-05-19 20:04:24.822927 [DEBUG] switch_channel.c:2608 Send signal
sofia/internal/sip:sip3779100 at 192.168.5.21:5062 [KILL]
2011-05-19 20:04:24.822927 [DEBUG] switch_core_session.c:1114 Send
signal sofia/internal/sip:sip3779100 at 192.168.5.21:5062 [BREAK]
2011-05-19 20:04:24.822927 [CONSOLE] switch_cpp.cpp:1197 API cmd
result: [+OK
]2011-05-19 20:04:24.822927 [DEBUG] mod_python.c:186 Finished calling
python script
2011-05-19 20:04:24.822927 [DEBUG] switch_cpp.cpp:988
sofia/external/907388397 at 10.34.0.4 destroy/unlink session from object
2011-05-19 20:04:24.822927 [DEBUG] switch_core_state_machine.c:497
Hangup Command with Session python(cleanup
f84558f4-46e9-4f8a-a546-7edfd6fd0d5e):

If I KILL the uuids by api hangup hook - there is no DEBUG, but still
the call...

2011-05-19 20:04:24.822927 [CONSOLE] switch_cpp.cpp:1197 hangup hook,
UUIDS: f84558f4-46e9-4f8a-a546-7edfd6fd0d5e
2011-05-19 20:04:24.822927 [CONSOLE] switch_cpp.cpp:1197 API cmd:
[uuid_setvar f84558f4-46e9-4f8a-a546-7edfd6fd0d5e disposition
ORIGINATOR_CANCEL]
2011-05-19 20:04:24.822927 [CONSOLE] switch_cpp.cpp:1197 API cmd result: [+OK
]2011-05-19 20:04:24.822927 [CONSOLE] switch_cpp.cpp:1197 API cmd:
[uuid_kill f84558f4-46e9-4f8a-a546-7edfd6fd0d5e]

show version
FreeSWITCH Version 1.0.head (git-fccbba5 2011-05-18 19-00-42 -0400)

Seems JOB is detached from UUID - but still not killed itself.