7 Replies Latest reply on Sep 11, 2016 12:54 PM by EdStevens

    Analyzing SQLDev connections in listener log

    EdStevens

      Oracle 11.2.0.4 SE-One 64-bit

      Oracle Linux 5

       

      My real goal is to get a better understanding of some entries in my listener log.  But after some initial reading I am using SQLDev to generate the activity and have come to the point of asking a few questions.  Hopefully the answers as regards SQL Dev will give me some insight into other jdbc apps.

       

      In trying to analyze the listener log to determine who/what/hwere of the clients, I get a fair amount of "host=_jdbc_ "  (instead of a host name or ip address), and "program=null" (or simply 'program=") Since the listener log reports "host" in both the 'connect' and the 'address' fields, I was able to track some of these back to my own desktop.  In those, some reported

       

      (CONNECT_DATA=(CID=(PROGRAM=SQL Developer)(HOST=__jdbc__)(USER=estevens)
      

       

      While others reported

      (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))
      

       

      The first was easy enough (up to a point) but the second was a real mystery.  The only jdbc program I ever use to connect to that database is SQL Dev.  And in the first sample, it was clearly identified as such.  So what what was the second?

       

      So I set up this test. While running 'tail -f listener.log | grep jdbc' . . .

       

      Connect with a SQL Dev connection defined as connection type = basic.  That resulted in

      09-SEP-2016 10:46:09 * (CONNECT_DATA=(CID=(PROGRAM=SQL Developer)(HOST=__jdbc__)(USER=estevens))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.**.**.12)(PORT=54190)) * establish * mydb1 * 0
      

       

      Connect with a SQL Dev connection defined as connection type = tns  That resulted in

      09-SEP-2016 10:46:09 * (CONNECT_DATA=(CID=(PROGRAM=SQL Developer)(HOST=__jdbc__)(USER=estevens))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.**.**.12)(PORT=54190)) * establish * mydb1 * 0

      09-SEP-2016 10:47:32 * (CONNECT_DATA=(CID=(PROGRAM=SQL Developer)(HOST=__jdbc__)(USER=estevens))(SERVICE_NAME=mydb1)) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.**.**.12)(PORT=54196)) * establish * mydb1 * 0
      

      Notice the difference after '(SERVICE_NAME=mydb1) ....

       

      Next, thinking there might be some sort of connection pooling going on, I started another instance of SQL Dev.  Didn't even try to make a connection.  Just started it, and got the following:

      09-SEP-2016 10:50:25 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.**.**.12)(PORT=54204)) * establish * mydb1 * 0
      09-SEP-2016 10:50:26 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.**.**.12)(PORT=54207)) * establish * mydb1 * 0
      09-SEP-2016 10:50:28 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb2)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.**.**.12)(PORT=54217)) * establish * mydb2 * 0
      

       

      Two connections to my original db, and even more surprising, a connection to another db on that server.

       

      So, what's going on here?  How am I to interpret and understand this?

        • 1. Re: Analyzing SQLDev connections in listener log
          thatJeffSmith-Oracle

          each connection to sqldev actually starts 2 oracle database connections

           

          1 handles the work you ask us to do - run queries, go get a table in the editor.

          The other runs queries for the Code Insight feature - as you type in the editor, it will get a list of column names for a table, for example.

           

          If you open an unshared worksheet, that will open yet ANOTHER connection - that's dedicated to running the queries in that worksheet for you, in case they're long running, and you don't want to freeze up the rest of SQL Dev while you wait for it to finish.

           

          Tools > Monitor Sessions or querying v$session will show you from the db perspective what's in the db, doing what.

          • 2. Re: Analyzing SQLDev connections in listener log
            EdStevens

            Jeff Smith Sqldev Pm-Oracle wrote:

             

            each connection to sqldev actually starts 2 oracle database connections

             

            1 handles the work you ask us to do - run queries, go get a table in the editor.

            The other runs queries for the Code Insight feature - as you type in the editor, it will get a list of column names for a table, for example.

             

            If you open an unshared worksheet, that will open yet ANOTHER connection - that's dedicated to running the queries in that worksheet for you, in case they're long running, and you don't want to freeze up the rest of SQL Dev while you wait for it to finish.

             

            Tools > Monitor Sessions or querying v$session will show you from the db perspective what's in the db, doing what.

            That doesn't seem to jive with what I'm seeing in the listener log.

             

            oracle:mydb2$ tail -f listener.log |grep jdbc
            

            -- on opening SQLDev - no connections requested ...

             

            09-SEP-2016 14:01:23 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60307)) * establish * mydb1 * 0
            09-SEP-2016 14:01:23 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60309)) * establish * mydb1 * 0
            09-SEP-2016 14:01:25 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb2)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60317)) * establish * mydb2 * 0
            

             

            All I did was launch SQL Dev.  Yet I got two connection requests to 'mydb1' (obfuscated name) and one request to 'mydb2'.   ?!?!?!

            And it gives 'PROGRAM=null.    ?!?!?

             

            ---- open 'basic' connection to mydb1

            09-SEP-2016 14:04:28 * (CONNECT_DATA=(CID=(PROGRAM=SQL Developer)(HOST=__jdbc__)(USER=estevens))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60392)) * establish * mydb1 * 0
            

             

            ---- open 'tns' connection to mydb1

            09-SEP-2016 14:05:40 * (CONNECT_DATA=(CID=(PROGRAM=SQL Developer)(HOST=__jdbc__)(USER=estevens))(SERVICE_NAME=mydb1)) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60393)) * establish * mydb1 * 0
            

            Both at least identify the requesting program, though they report slightly different details in the CONNECT_DATA

             

            -- open second worksheet on 'basic' connection

            <no listener entry>

             

            -- open second worksheet on 'tns' connection

            <no listener entry>

             

             

            -- open another instance of SQL Developer

            09-SEP-2016 14:08:51 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60409)) * establish * mydb1 * 0
            09-SEP-2016 14:08:52 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb1)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60411)) * establish * mydb1 * 0
            09-SEP-2016 14:08:53 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=mydb2)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.18.1.12)(PORT=60419)) * establish * mydb2 * 0
            

            Again, I didn't even get a chance to request a connection ... it threw these immediately on launching sqldev.  Two on one database, one on another.

            • 3. Re: Analyzing SQLDev connections in listener log
              thatJeffSmith-Oracle

              what's running on those connections?

               

              SQL Developer doesn't automatically connect to any database on startup, it's a feature request we've rejected actually.

              • 4. Re: Analyzing SQLDev connections in listener log
                thatJeffSmith-Oracle

                we DO however, TNSPing each db in your connection list at startup - that's different than a connection request, and there's no actual connection being made

                • 5. Re: Analyzing SQLDev connections in listener log
                  EdStevens

                  Jeff Smith Sqldev Pm-Oracle wrote:

                   

                  we DO however, TNSPing each db in your connection list at startup - that's different than a connection request, and there's no actual connection being made

                  Ah!  At first blush, that explains everything I was seeing.

                  Except .... when I do a tnsping from a command line, it is reported in the listener log as simply

                   

                  10-SEP-2016 09:28:04 * ping * 0

                   

                   

                  Whereas the connection request from SQL Dev (the "automagic" one on startup) looks like this:

                   

                  10-SEP-2016 09:27:12 * (CONNECT_DATA=(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))(SERVICE_NAME=tulsa)(CID=(PROGRAM=null)(HOST=__jdbc__)(USER=null))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.56.1)(PORT=51022)) * establish * tulsa * 0

                   

                  Which for all the world looks like an actual connection request   (* establish * tulsa * 0). 

                   

                  So I'd have to conclude that SQL Dev is doing somethign a bit more sophisticated than what is done by the command line tnsping, but in principle is the same.  But that does at least explain these 'phantom' entries (program=null, user=null) in my analysis.

                  • 6. Re: Analyzing SQLDev connections in listener log
                    thatJeffSmith-Oracle

                    yeah we actually look to see if the db is available vs if the listener can resolve the request

                    • 7. Re: Analyzing SQLDev connections in listener log
                      EdStevens

                      Jeff Smith Sqldev Pm-Oracle wrote:

                       

                      yeah we actually look to see if the db is available vs if the listener can resolve the request

                      That explains everything then.  Thank your for your time.