Apr  2 14:36:56 VERBOSE[1896]:   == Spawn extension (default, 600, 1) exited non-zero on 'SIP/3000-702c'
Apr  2 14:36:56 DEBUG[1896]: Setting NAT on RTP to 0
Apr  2 14:36:56 DEBUG[1896]: update_user_counter(3000) - decrement inUse counter
Apr  2 14:36:56 DEBUG[1896]: Check for res for 3000
Apr  2 14:36:56 DEBUG[1896]: Call from user '3000' is 1 out of 0
Apr  2 14:36:56 DEBUG[1896]: build_route: Contact hop: <sip:softphone@192.168.1.2:5060>
Apr  2 14:36:56 VERBOSE[1896]:     -- Executing Playback("SIP/3000-c714", "demo-echotest") in new stack
Apr  2 14:36:56 DEBUG[1896]: Stopping retransmission on 'ea02120af423e03c@Ym94Mg..' of Response 1: Found
Apr  2 14:36:56 DEBUG[1896]: Ooh, format changed from unknown to ulaw
Apr  2 14:36:56 VERBOSE[1896]:     -- Playing 'demo-echotest' (language 'en')
Apr  2 14:36:57 DEBUG[1896]: Request to schedule in the past?!?!
Apr  2 14:36:58 WARNING[1896]: Maximum retries exceeded on call 398150e9375216574d9a2fdb76c3625e@192.168.1.113 for seqno 102 (Non-critical Request)
Apr  2 14:36:58 WARNING[1896]: Failed to write frame
Apr  2 14:36:58 VERBOSE[1896]:   == Spawn extension (default, 600, 1) exited non-zero on 'SIP/3000-c714'
Apr  2 14:36:58 DEBUG[1896]: update_user_counter(3000) - decrement inUse counter
Apr  2 14:38:12 NOTICE[1896]: Request to schedule in the past?!?!