12/22/2012 04:14:49 EST connection [1871] : getting unix socket...
12/22/2012 04:14:49 EST connection [1871] : opening /usr/local/firstworks/var/sqlrelay/tmp/sockseq
12/22/2012 04:14:49 EST connection [1871] : locking...
12/22/2012 04:14:49 EST connection [1871] : got sequence number: 22
12/22/2012 04:14:49 EST connection [1871] : writing new sequence number: 23
12/22/2012 04:14:49 EST connection [1871] : unlocking...
12/22/2012 04:14:49 EST connection [1871] : done getting unix socket
12/22/2012 04:14:49 EST connection [1871] : attaching to shared memory and semaphores id filename: /usr/local/firstworks/var/sqlrelay/tmp/ipc/oracletest
12/22/2012 04:14:49 EST connection [1871] : attaching to shared memory...
12/22/2012 04:14:49 EST connection [1871] : attaching to semaphores...
12/22/2012 04:14:49 EST connection [1871] : done attaching to shared memory and semaphores
12/22/2012 04:14:49 EST connection [1871] : logging in...
12/22/2012 04:14:51 EST connection [1871] : cache size 0
12/22/2012 04:14:52 EST connection [1871] : 
12/22/2012 04:14:52 EST connection [1871] : done logging in
12/22/2012 04:14:52 EST connection [1872] : setting autocommit...
12/22/2012 04:14:52 EST connection [1872] : done setting autocommit
12/22/2012 04:14:52 EST connection [1872] : initializing cursors...
12/22/2012 04:14:52 EST connection [1872] : done initializing cursors
12/22/2012 04:14:52 EST connection [1872] : incrementing connection count...
12/22/2012 04:14:52 EST connection [1872] : acquiring connection count mutex
12/22/2012 04:14:52 EST connection [1872] : done acquiring connection count mutex
12/22/2012 04:14:52 EST connection [1872] : releasing connection count mutex
12/22/2012 04:14:52 EST connection [1872] : done releasing connection count mutex
12/22/2012 04:14:52 EST connection [1872] : done incrementing connection count
12/22/2012 04:14:52 EST connection [1872] : creating /usr/local/firstworks/var/sqlrelay/tmp/ipc/oracletest-db
12/22/2012 04:14:52 EST connection [1872] : waiting for available database...
12/22/2012 04:14:52 EST connection [1872] : database is available
12/22/2012 04:14:52 EST connection [1872] : initializing session...
12/22/2012 04:14:52 EST connection [1872] : done initializing session...
12/22/2012 04:14:52 EST connection [1872] : announcing availability...
12/22/2012 04:14:52 EST connection [1872] : registering for handoff...
12/22/2012 04:14:52 EST connection [1872] : handoffsockname: /usr/local/firstworks/var/sqlrelay/tmp/sockets/oracletest-handoff
12/22/2012 04:14:52 EST connection [1872] : trying...
12/22/2012 04:14:52 EST connection [1872] : done registering for handoff
12/22/2012 04:14:52 EST connection [1872] : acquiring announce mutex
12/22/2012 04:14:52 EST connection [1872] : done acquiring announce mutex
12/22/2012 04:14:52 EST connection [1872] : handoff=pass
12/22/2012 04:14:52 EST connection [1872] : signalling listener to read
12/22/2012 04:14:52 EST connection [1872] : done signalling listener to read
12/22/2012 04:14:52 EST connection [1872] : waiting for listener
12/22/2012 04:15:11 EST connection [1872] : done waiting for listener
12/22/2012 04:15:11 EST connection [1872] : releasing announce mutex
12/22/2012 04:15:11 EST connection [1872] : done releasing announce mutex
12/22/2012 04:15:11 EST connection [1872] : done announcing availability...
12/22/2012 04:15:11 EST connection [1872] : waiting for client...
12/22/2012 04:15:11 EST connection [1872] : pass succeeded
12/22/2012 04:15:11 EST connection [1872] : done waiting for client
12/22/2012 04:15:11 EST connection [1872] : client session...
12/22/2012 04:15:11 EST connection [1872] : 
12/22/2012 04:15:11 EST connection [1872] : getting command...
12/22/2012 04:15:11 EST connection [1872] : done getting command
12/22/2012 04:15:11 EST connection [1872] : authenticate
12/22/2012 04:15:11 EST connection [1872] : authenticate...
12/22/2012 04:15:11 EST connection [1872] : authentication was done on listener
12/22/2012 04:15:11 EST connection [1872] : getting command...
12/22/2012 04:15:11 EST connection [1872] : done getting command
12/22/2012 04:15:11 EST connection [1872] : getting a cursor...
12/22/2012 04:15:11 EST connection [1872] : available cursor: 0
12/22/2012 04:15:11 EST connection [1872] : done getting a cursor
12/22/2012 04:15:11 EST connection [1872] : new query
12/22/2012 04:15:11 EST connection [1872] : handling query...
12/22/2012 04:15:11 EST connection [1872] : getting client info...
12/22/2012 04:15:11 EST connection [1872] : clientinfolen: 0
12/22/2012 04:15:11 EST connection [1872] : clientinfo: 
12/22/2012 04:15:11 EST connection [1872] : getting clientinfo succeeded
12/22/2012 04:15:11 EST connection [1872] : getting query...
12/22/2012 04:15:11 EST connection [1872] : querylength: 18
12/22/2012 04:15:11 EST connection [1872] : query: select 1 from dual
12/22/2012 04:15:11 EST connection [1872] : getting query succeeded
12/22/2012 04:15:11 EST connection [1872] : getting input binds...
12/22/2012 04:15:11 EST connection [1872] : done getting input binds
12/22/2012 04:15:11 EST connection [1872] : getting output binds...
12/22/2012 04:15:11 EST connection [1872] : done getting output binds
12/22/2012 04:15:11 EST connection [1872] : get send column info...
12/22/2012 04:15:11 EST connection [1872] : send column info
12/22/2012 04:15:11 EST connection [1872] : done getting send column info...
12/22/2012 04:15:11 EST connection [1872] : processing query...
12/22/2012 04:15:11 EST connection [1872] : preparing/executing...
12/22/2012 04:15:11 EST connection [1872] : commit or rollback check...
12/22/2012 04:15:11 EST connection [1872] : done with commit or rollback check
12/22/2012 04:15:11 EST connection [1872] : processing query succeeded
12/22/2012 04:15:11 EST connection [1872] : done processing query
12/22/2012 04:15:11 EST connection [1872] : returning result set header...
12/22/2012 04:15:11 EST connection [1872] : returning row counts...
12/22/2012 04:15:11 EST connection [1872] : sending row counts...
12/22/2012 04:15:11 EST connection [1872] : actual rows unknown
12/22/2012 04:15:11 EST connection [1872] : affected rows: 0
12/22/2012 04:15:11 EST connection [1872] : done sending row counts
12/22/2012 04:15:11 EST connection [1872] : done returning row counts
12/22/2012 04:15:11 EST connection [1872] : column info will be sent
12/22/2012 04:15:11 EST connection [1872] : returning column counts...
12/22/2012 04:15:11 EST connection [1872] : done returning column counts
12/22/2012 04:15:11 EST connection [1872] : sending column type format...
12/22/2012 04:15:11 EST connection [1872] : id's
12/22/2012 04:15:11 EST connection [1872] : done sending column type format
12/22/2012 04:15:11 EST connection [1872] : returning column info...
12/22/2012 04:15:11 EST connection [1872] : 1:48:2 (0,129) 
12/22/2012 04:15:11 EST connection [1872] : done returning column info
12/22/2012 04:15:11 EST connection [1872] : returning 0 output bind values: 
12/22/2012 04:15:11 EST connection [1872] : done returning output bind values
12/22/2012 04:15:11 EST connection [1872] : done returning result set header
12/22/2012 04:15:11 EST connection [1872] : handle query succeeded
12/22/2012 04:15:11 EST connection [1872] : returning result set data...
12/22/2012 04:15:11 EST connection [1872] : skipping 0 rows...
12/22/2012 04:15:11 EST connection [1872] : done skipping rows
12/22/2012 04:15:11 EST connection [1872] : fetching 100 rows...
12/22/2012 04:15:11 EST connection [1872] : "1",
12/22/2012 04:15:11 EST connection [1872] : done returning result set data
12/22/2012 04:15:11 EST connection [1872] : 
12/22/2012 04:15:11 EST connection [1872] : getting command...
12/22/2012 04:15:11 EST connection [1872] : done getting command
12/22/2012 04:15:11 EST connection [1872] : getting a cursor...
12/22/2012 04:15:11 EST connection [1872] : done getting a cursor
12/22/2012 04:15:11 EST connection [1872] : aborting result set...
12/22/2012 04:15:11 EST connection [1872] : done aborting result set
12/22/2012 04:15:11 EST connection [1872] : getting command...
12/22/2012 04:15:11 EST connection [1872] : done getting command
12/22/2012 04:15:11 EST connection [1872] : ending session...
12/22/2012 04:15:11 EST connection [1872] : aborting all cursors...
12/22/2012 04:15:11 EST connection [1872] : done aborting all cursors
12/22/2012 04:15:11 EST connection [1872] : setting autocommit...
12/22/2012 04:15:11 EST connection [1872] : done setting autocommit
12/22/2012 04:15:11 EST connection [1872] : done ending session
12/22/2012 04:15:11 EST connection [1872] : waiting for client to close the connection...
12/22/2012 04:15:11 EST connection [1872] : done waiting for client to close the connection
12/22/2012 04:15:11 EST connection [1872] : closing the client socket...
12/22/2012 04:15:11 EST connection [1872] : done closing the client socket
12/22/2012 04:15:11 EST connection [1872] : closing sockets from a previously suspended session...
12/22/2012 04:15:11 EST connection [1872] : done closing sockets from a previously suspended session...
12/22/2012 04:15:11 EST connection [1872] : client ended the session
12/22/2012 04:15:11 EST connection [1872] : done with client session
12/22/2012 04:15:11 EST connection [1872] : decrementing session count...
12/22/2012 04:15:11 EST connection [1872] : done decrementing session count
12/22/2012 04:15:11 EST connection [1872] : waiting for available database...
12/22/2012 04:15:11 EST connection [1872] : database is available
12/22/2012 04:15:11 EST connection [1872] : initializing session...
12/22/2012 04:15:11 EST connection [1872] : done initializing session...
12/22/2012 04:15:11 EST connection [1872] : announcing availability...
12/22/2012 04:15:11 EST connection [1872] : acquiring announce mutex