[Feb 25 16:46:24] Asterisk 11.1.0 built by root @ ubuntu on a x86_64 running Linux on 2013-02-25 15:15:27 UTC
[Feb 25 16:46:24] DEBUG[30390] config.c: Parsing /etc/asterisk/logger.conf
[Feb 25 16:46:24] VERBOSE[30390] config.c:   == Parsing '/etc/asterisk/logger.conf': Found
[Feb 25 16:46:24] VERBOSE[30390] logger.c:  Asterisk Queue Logger restarted
[Feb 25 16:46:29] VERBOSE[30358] res_xmpp.c: 
<--- XMPP keep alive from 'asterisk' --->
[Feb 25 16:46:33] VERBOSE[30358] res_xmpp.c: 
<--- XMPP received from 'asterisk' --->
<
<------------->
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XML parsing successful
[Feb 25 16:46:33] VERBOSE[30358] res_xmpp.c: 
<--- XMPP received from 'asterisk' --->
message from="pubsub.rnewton-office-lab" to="pbx2@rnewton-office-lab" id="device_state__pbx2@rnewton-office-lab__cQQj8"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="device_state"><item id="Custom:mystate" node="Custom:mystate"><state xmlns="http://asterisk.org" eid="00:21:9b:02:8b:72" cachable="1">INUSE</state></item></items></event><headers xmlns="http://jabber.org/protocol/shim"><header name="pubsub#subid">Ji5Eto4h2CHUeqR6mBYk9hF9EL1C6aE72nxIXY1w</header></headers></message>
<------------->
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XMPP client 'asterisk' received a message
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XML parsing successful
[Feb 25 16:46:33] DEBUG[30346] res_xmpp.c: Returning here
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Processing device state change for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Adding per-server state of 'Not in use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Adding per-server state of 'In use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Aggregate devstate result is 'In use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Aggregate state for device 'Custom:mystate' has changed to 'In use'
[Feb 25 16:46:33] DEBUG[30388] app_queue.c: Device 'Custom:mystate' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Feb 25 16:46:33] DEBUG[30354] app_queue.c: Extension '1234@devstate_test' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Feb 25 16:46:33] VERBOSE[30358] res_xmpp.c: 
<--- XMPP received from 'asterisk' --->
<
<------------->
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XML parsing successful
[Feb 25 16:46:33] VERBOSE[30358] res_xmpp.c: 
<--- XMPP received from 'asterisk' --->
message from="pubsub.rnewton-office-lab" to="pbx2@rnewton-office-lab" id="Custom:mystate__pbx2@rnewton-office-lab__e78OR"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="Custom:mystate"><item id="Custom:mystate"><state xmlns="http://asterisk.org" eid="00:21:9b:02:8b:72" cachable="1">INUSE</state></item></items></event><headers xmlns="http://jabber.org/protocol/shim"><header name="pubsub#subid">L6bKE3zuvOd8SLPQ6w1LnRD3HqE2mXBgWjHjb8E3</header></headers></message>
<------------->
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XMPP client 'asterisk' received a message
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XML parsing successful
[Feb 25 16:46:33] DEBUG[30346] res_xmpp.c: Returning here
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Processing device state change for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Adding per-server state of 'Not in use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Adding per-server state of 'In use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Aggregate devstate result is 'In use' for 'Custom:mystate'
[Feb 25 16:46:33] VERBOSE[30358] res_xmpp.c: 
<--- XMPP received from 'asterisk' --->
<
<------------->
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XML parsing successful
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Aggregate state for device 'Custom:mystate' has not changed from 'In use'
[Feb 25 16:46:33] VERBOSE[30358] res_xmpp.c: 
<--- XMPP received from 'asterisk' --->
message from="pubsub.rnewton-office-lab" to="pbx2@rnewton-office-lab/astvoip2" id="Custom:mystate__pbx2@rnewton-office-lab__oU8m2"><event xmlns="http://jabber.org/protocol/pubsub#event"><items node="Custom:mystate"><item id="Custom:mystate"><state xmlns="http://asterisk.org" eid="00:21:9b:02:8b:72" cachable="1">INUSE</state></item></items></event><headers xmlns="http://jabber.org/protocol/shim"><header name="pubsub#subid">9R7m9SUup2tGuvDMXw8WLCsh33z8BhxKiKPK349e</header></headers></message>
<------------->
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XMPP client 'asterisk' received a message
[Feb 25 16:46:33] DEBUG[30358] res_xmpp.c: XML parsing successful
[Feb 25 16:46:33] DEBUG[30346] res_xmpp.c: Returning here
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Processing device state change for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Adding per-server state of 'Not in use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Adding per-server state of 'In use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Aggregate devstate result is 'In use' for 'Custom:mystate'
[Feb 25 16:46:33] DEBUG[30379] devicestate.c: Aggregate state for device 'Custom:mystate' has not changed from 'In use'