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:@//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@xxxxxxxxx>
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
--
//www.freelists.org/webpage/oracle-l
