Re: user_id 0 in V$ACTIVE_SESSION_HISTORY/DBA_HIST_ACTIVE_SESS_HISTORY

Thank you very much Mikhail!
Excellent test case!

Best regards
Dimitre

Il dom 27 dic 2020, 01:17 Mikhail Velikikh <mvelikikh_at_gmail.com> ha scritto:

> Hi Dimitre,
>
> Once I have seen it in an environment with ORDS/APEX. Another time it was
> due to failed JDBC connections. Since ORDS uses JDBC, I think it is mostly
> JDBC related rather than OAuth authentication itself.
>
> I can reproduce it with the following Java class that uses invalid
> database credentials so as to receive ORA-1017:
>
> import java.sql.Connection;
> import java.sql.DriverManager;
> import java.sql.SQLException;
>
> public class JDBCExample {
>
> public static void main(String[] args) {
>
> //
> https://docs.oracle.com/javase/8/docs/api/java/sql/package-summary.html#package.description
> // auto java.sql.Driver discovery -- no longer need to load a
> java.sql.Driver class via Class.forName
>
> // register JDBC driver, optional since java 1.6
> /*try {
> Class.forName("oracle.jdbc.driver.OracleDriver");
> } catch (ClassNotFoundException e) {
> e.printStackTrace();
> }*/
>
> // Oracle SID = orcl , find yours in tnsname.ora
> try (Connection conn = DriverManager.getConnection(
> "jdbc:oracle:thin:_at_//localhost/XEPDB1", "x", "y")) {
>
> if (conn != null) {
> System.out.println("Connected to the database!");
> } else {
> System.out.println("Failed to make connection!");
> }
>
> } catch (SQLException e) {
> System.err.format("SQL State: %s\n%s", e.getSQLState(),
> e.getMessage());
> } catch (Exception e) {
> e.printStackTrace();
> }
>
> }
> }
>
> I enabled SQL*Net server trace, and I also fired a script polling
> v$session.
> That is what I got in v$session - user#=0, top_level_call#=115 which
> corresponds to OAUTH in my XE database.
>
>
> <ROWSET>
> <ROW>
> * <SAMPLE_TIME>26-DEC-20 11.52.25.741 PM</SAMPLE_TIME>*
> <SADDR>000000006AAC94D0</SADDR>
> <SID>58</SID>
> <SERIAL_x0023_>47422</SERIAL_x0023_>
> <AUDSID>0</AUDSID>
> <PADDR>000000006AF5F528</PADDR>
> * <USER_x0023_>0</USER_x0023_>*
> <COMMAND>0</COMMAND>
> <OWNERID>2147483644</OWNERID>
> <STATUS>ACTIVE</STATUS>
> <SERVER>DEDICATED</SERVER>
> <SCHEMA_x0023_>0</SCHEMA_x0023_>
> <SCHEMANAME>SYS</SCHEMANAME>
> <OSUSER>oracle</OSUSER>
> <PROCESS>1234</PROCESS>
> <MACHINE>localhost.localdomain</MACHINE>
> <PORT>51416</PORT>
> <TERMINAL>unknown</TERMINAL>
> <PROGRAM>JDBC Thin Client</PROGRAM>
> <TYPE>USER</TYPE>
> <SQL_ADDRESS>00</SQL_ADDRESS>
> <SQL_HASH_VALUE>0</SQL_HASH_VALUE>
> <SQL_CHILD_NUMBER>0</SQL_CHILD_NUMBER>
> <PREV_SQL_ADDR>00</PREV_SQL_ADDR>
> <PREV_HASH_VALUE>0</PREV_HASH_VALUE>
> <PREV_CHILD_NUMBER>0</PREV_CHILD_NUMBER>
> <MODULE>JDBC Thin Client</MODULE>
> <MODULE_HASH>2546894660</MODULE_HASH>
> <ACTION_HASH>0</ACTION_HASH>
> <FIXED_TABLE_SEQUENCE>13040999</FIXED_TABLE_SEQUENCE>
> <ROW_WAIT_OBJ_x0023_>-1</ROW_WAIT_OBJ_x0023_>
> <ROW_WAIT_FILE_x0023_>0</ROW_WAIT_FILE_x0023_>
> <ROW_WAIT_BLOCK_x0023_>0</ROW_WAIT_BLOCK_x0023_>
> <ROW_WAIT_ROW_x0023_>0</ROW_WAIT_ROW_x0023_>
> * <TOP_LEVEL_CALL_x0023_>115</TOP_LEVEL_CALL_x0023_>*
> <LOGON_TIME>26.12.2020 23:52:24</LOGON_TIME>
> <LAST_CALL_ET>1</LAST_CALL_ET>
> <PDML_ENABLED>NO</PDML_ENABLED>
> <FAILOVER_TYPE>NONE</FAILOVER_TYPE>
> <FAILOVER_METHOD>NONE</FAILOVER_METHOD>
> <FAILED_OVER>NO</FAILED_OVER>
> <PDML_STATUS>DISABLED</PDML_STATUS>
> <PDDL_STATUS>DISABLED</PDDL_STATUS>
> <PQ_STATUS>DISABLED</PQ_STATUS>
> <CURRENT_QUEUE_DURATION>0</CURRENT_QUEUE_DURATION>
> <BLOCKING_SESSION_STATUS>NO HOLDER</BLOCKING_SESSION_STATUS>
> <FINAL_BLOCKING_SESSION_STATUS>NO
> HOLDER</FINAL_BLOCKING_SESSION_STATUS>
> <SEQ_x0023_>5</SEQ_x0023_>
> <EVENT_x0023_>1381</EVENT_x0023_>
> * <EVENT>Failed Logon Delay</EVENT>*
> <P1>100</P1>
> <P1RAW>0000000000000064</P1RAW>
> <P2>0</P2>
> <P2RAW>00</P2RAW>
> <P3>0</P3>
> <P3RAW>00</P3RAW>
> <WAIT_CLASS_ID>1893977003</WAIT_CLASS_ID>
> <WAIT_CLASS_x0023_>0</WAIT_CLASS_x0023_>
> <WAIT_CLASS>Other</WAIT_CLASS>
> <WAIT_TIME>0</WAIT_TIME>
> <SECONDS_IN_WAIT>1</SECONDS_IN_WAIT>
> <STATE>WAITING</STATE>
> <WAIT_TIME_MICRO>628776</WAIT_TIME_MICRO>
> <TIME_REMAINING_MICRO>371224</TIME_REMAINING_MICRO>
> <TIME_SINCE_LAST_WAIT_MICRO>0</TIME_SINCE_LAST_WAIT_MICRO>
> <SERVICE_NAME>xepdb1</SERVICE_NAME>
> <SQL_TRACE>DISABLED</SQL_TRACE>
> <SQL_TRACE_WAITS>FALSE</SQL_TRACE_WAITS>
> <SQL_TRACE_BINDS>FALSE</SQL_TRACE_BINDS>
> <SQL_TRACE_PLAN_STATS>FIRST EXEC</SQL_TRACE_PLAN_STATS>
> <SESSION_EDITION_ID>0</SESSION_EDITION_ID>
> <CREATOR_ADDR>000000006AF5F528</CREATOR_ADDR>
> <CREATOR_SERIAL_x0023_>71</CREATOR_SERIAL_x0023_>
> <SQL_TRANSLATION_PROFILE_ID>0</SQL_TRANSLATION_PROFILE_ID>
> <PGA_TUNABLE_MEM>0</PGA_TUNABLE_MEM>
> <SHARD_DDL_STATUS>DISABLED</SHARD_DDL_STATUS>
> <CON_ID>3</CON_ID>
> <PLSQL_DEBUGGER_CONNECTED>FALSE</PLSQL_DEBUGGER_CONNECTED>
> </ROW>
> </ROWSET>
>
> select * from v$toplevelcall where top_level_call#=115;
>
> TOP_LEVEL_CALL# TOP_LEVEL_CALL_NAME
> CON_ID
> ---------------
> ---------------------------------------------------------------- ----------
> *115 *OAUTH
> 0
>
> This is the relevant part of my SQL*Net trace file processed by trcasst:
>
> ---> Send 241 bytes - Data packet timestamp=020-12-26 23:52:24.270
> Set protocol (TTIPRO)
> Operation 01 (con) Send protocol version=6
> Originating platform: x86_64/Linux 2.4.xx
>
> <--- Received 2684 bytes - Data packet timestamp=020-12-26 23:52:24.843
> Set datatypes (TTIDTY)
>
> ---> Send 2697 bytes - Data packet timestamp=020-12-26 23:52:24.851
> Set datatypes (TTIDTY)
>
> <--- Received 169 bytes - Data packet timestamp=020-12-26 23:52:24.937
> Start of user function (TTIFUN)
> Get the session key (OSESSKEY)
>
> ---> Send 370 bytes - Data packet timestamp=020-12-26 23:52:24.979
> Return opi parameter (TTIRPA)
>
>
>
>
>
>
>
> *<--- Received 1207 bytes - Data packet timestamp=020-12-26
> 23:52:25.108Start of user function (TTIFUN) Generic authentication
> call (OAUTH)---> Send 11 bytes - Marker packet timestamp=020-12-26
> 23:52:26.128 One data byte. Hex character sent over to the
> server: 1*
>
> ---> Send 11 bytes - Marker packet timestamp=020-12-26 23:52:26.129
> One data byte.
> Hex character sent over to the server: 2
>
> <--- Received 11 bytes - Marker packet timestamp=020-12-26 23:52:26.131
> One data byte.
> Hex character sent over to the server: 2
>
> <--- Received 10 bytes - Data packet timestamp=020-12-26 23:52:26.134
> Data Packet flags:
> End of file
>
> Please notice that the sample_time when I made V$SESSION snapshot is
> 23:52:25.741. The time corresponds to this generic authentication call
> (OAUTH) line.
> The 'Failed Logon Delay' is self-explanatory as well. Provided you have
> some auditing in place, it is more likely you will see some transaction
> calls you mentioned.
> I cannot reproduce it with valid connections at the moment, but I guess it
> can happen too.
>
>
> On Sat, 26 Dec 2020 at 21:50, Radoulov, Dimitre <cichomitiko_at_gmail.com>
> wrote:
>
>> Hello all,
>>
>> I noticed that some records in the active session history views report
>> user_id = 0 (sys) and machine indicating remote clients which I'm sure
>> are not using sys user to connect to the database. In my case the
>> TOP_LEVEL_CALL_NAMEs are LOGOFF, OAUTH, VERSION2, ROLLBACK, Transaction
>> Commit/Rollback.
>>
>> I suppose these are some internal clean up operations, but I don't
>> understand why some of them are associated with remote clients and
>> others with the database server.
>>
>> Does anybody know why this might be happening?
>>
>> Thanks!
>>
>> Regards
>> Dimitre
>>
>> --
>> http://www.freelists.org/webpage/oracle-l
>>
>>
>>

--
http://www.freelists.org/webpage/oracle-l