TTC error: received code 28 during response reading after "alter session set container=pdb1"

[Tommi2Day]

I can't execALTER SESSION SET CONTAINER=PDB1, which results in TTC error: received code 28 during response reading

func doSql( dbh *sql.dbh,sql string) (error) {
   _,err:=dbh.Exec(sql)
  return err
}

In the same connection ALTER SESSION SET NLS_DATE_FORMAT='YYY-MM-DD HH24:MI:SS' executed without problems

Database behind is a RAC CDB, if this matters. Connected User is a C## common User with the needed privileges

testet with go-ora 2.7.9 and latest 2.7.11

[Tommi2Day]

with the "godror" driver there is no such error (but requires a client)

[sijms]

package main

import (
    "database/sql"
    "fmt"
    _ "github.com/sijms/go-ora/v2"
    "os"
)

func main() {
    conn, err := sql.Open("oracle", os.Getenv("DSN"))
    if err != nil {
        fmt.Println("can't connect: ", err)
        return
    }
    defer func() {
        err = conn.Close()
        if err != nil {
            fmt.Println("can't close connection: ", err)
        }
    }()

    _, err = conn.Exec("alter session set container=PDB")
    if err != nil {
        fmt.Println("can't alter session: ", err)
        return
    }
}

the code above pass without error my connection string using sys with single instance

would you share the return packet after execute the command which produce the TTC error?

[Tommi2Day]

would you share the return packet after execute the command which produce the TTC error? yes, i will try my best. Can you please tell me, how to catch this packet?

[sijms]

from trace file. you can use the following code to get trace file

urlOptions := map[string]string {
    "trace file": "trace.log",
}
databaseURL := go_ora.BuildUrl(server, port, service, user, password, urlOptions)
conn, err := sql.Open("oracle", databaseURL)

[Tommi2Day]

Here is the requested packet:

2023-08-04T12:57:47.7128: Connected 2023-08-04T12:57:47.7128: Database Version: 19.1.0.0.0 2023-08-04T12:57:47.7128: Exec With Context: 2023-08-04T12:57:47.7128: Exec: alter session set container=!redacted! 2023-08-04T12:57:47.7129: Write packet: 00000000 00 00 00 7c 06 00 00 00 00 00 24 89 6c dc 0c 68 |...|......$.l..h| 00000010 ec 29 a2 ee d4 91 b1 4a 90 05 33 60 a0 1c 38 6e |.).....J..3..8n| 00000020 36 b5 73 64 b2 30 c6 de 36 46 18 b1 c3 bc 4d d0 |6.sd.0..6F....M.| 00000030 e8 d9 f3 68 01 7c f7 99 ab 78 e0 0a 68 3c 33 08 |...h.|...x..h<3.| 00000040 9b 2a ae ca f7 15 45 fa c1 60 99 0c 4e 9f 81 83 |.*....E....N...| 00000050 29 96 e0 23 56 dd 2c c0 73 74 bd 84 bf 56 d9 97 |)..#V.,.st...V..| 00000060 c3 a0 14 e6 1f 30 89 4c ce 6c 4c 09 8a b3 e0 50 |.....0.L.lL....P| 00000070 55 69 59 e2 3e f1 dc 78 87 dd 09 00 |UiY.>..x....| 2023-08-04T12:57:47.7157: Read packet: 00000000 00 00 00 1c 06 20 00 00 00 00 aa 57 f3 16 08 6a |..... .....W...j| 00000010 d5 00 e2 53 a7 d2 15 3b 13 21 10 00 |...S...;.!..| 2023-08-04T12:57:47.7160: Close 2023-08-04T12:57:47.7160: Connection Closed

[sijms]

the data is encrypted so may be the issue occur with encryption I will test with encryption and tell you the result

[Tommi2Day]

Yep, sqlnet is using aes256 encryption

[sijms]

I test the command using AES256 encryption without errors

[sijms]

for me now the only untested situation is RAC and me be issue is related to it

[Tommi2Day]

Hm, If i can help you with some tests let me know.

[sijms]

could you connect without encryption to see what happens in log file?

[Tommi2Day]

Without encryption it works correctly. Do you need the log? I could send it per PN

[sijms]

ok I need to check if there is something strange also I need to ask you does error come every time or some time

[Tommi2Day]

it occurs each time on every (our) RAC Databases. It not happens if i connect to an oracle-xe 21.3 docker container und set sqlnet.encryption. see https://github.com/Tommi2Day/containertest

[sijms]

as I understand the error happen with RAC in encryption mode. so if you can use debugger like goland and log last packets unencrypted so I can detect in which stage the error happen.

[Tommi2Day]

i can do this. Where in your code would be the best place for the breakpoint where i can read out the packet?

[sijms]

all found in data_packet.go data that go to server: before encryption

data that received from server: after decryption

[Tommi2Day]

I was using goland debugger, but was unable to save the packet content. I placed an breakpoint in to line with conn.exec and those in data_paket.go as suggested. What i could see is there was first an unecrypted paket entering line 88 containing the connection string and next an paket with no readable content, but also with no encryption alg set in sessionctx.advancedService. Finally it tries to send OracleClientGo in Line44. Then i got connection timeout

[sijms]

it is better to add logging at that points for example fmt.Println()

or better use DataPacket.sessionCtx.ConnOption.Tracer.LogPacket("Write packet:", tmp) change write packet to read packet according to the operation and tmp is the []byte data which will be logged. this will make logging inline with other logging in trace.log file

because some oracle servers have small timeout so when you debug code and stop execution for a while the server hit timeout and close the connection so you got connection timeout

[sijms]

I think I should add these lines of logPacket in next release so encrypted data is readable for debugging

[sijms]

I update logging of Decrypted packet in v2.7.15

[Tommi2Day]

here we are

alter session set container=SQLDEPLOY 2023-08-22T11:16:22.0071: Write packet (Decrypted): 00000000 03 5e 00 02 80 21 00 01 01 25 01 01 0d 00 00 00 |.^...!...%......| 00000010 00 04 3f ff ff ff 00 00 00 00 00 00 00 00 00 00 |..?.............| 00000020 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| 00000030 00 25 61 6c 74 65 72 20 73 65 73 73 69 6f 6e 20 |.%alter session | 00000040 73 65 74 20 63 6f 6e 74 61 69 6e 65 72 3d 53 51 |set container=SQ| 00000050 4c 44 45 50 4c 4f 59 01 01 01 01 00 00 00 00 00 |LDEPLOY.........| 00000060 00 00 02 80 00 00 00 00 |........| 2023-08-22T11:16:22.0072: Write packet: 00000000 00 00 00 7c 06 00 00 00 00 00 47 cb 93 e2 06 ff |...|......G.....| 00000010 73 be c7 5e f7 34 95 37 f8 93 71 c9 11 81 db 75 |s..^.4.7..q....u| 00000020 74 ce 42 37 d8 17 36 d3 b2 f5 c1 81 66 24 ae fc |t.B7..6.....f$..| 00000030 1f 9b ca e6 d1 7f 51 c1 ad 46 ce 12 f2 45 d1 8e |......Q..F...E..| 00000040 c3 77 0d 4a c3 a3 17 5e ec 78 5f 42 8e e8 b3 68 |.w.J...^.x_B...h| 00000050 90 ea 26 6f 48 4f 9b d4 31 4b 99 30 89 71 d3 11 |..&oHO..1K.0.q..| 00000060 90 0b ec 38 48 bf 24 4c 31 c7 33 bf c3 7a 9e 26 |...8H.$L1.3..z.&| 00000070 f0 4a c7 1f 12 e5 ba 81 68 f3 09 00 |.J......h...| 2023-08-22T11:16:22.0294: Read packet: 00000000 00 00 00 1c 06 20 00 00 00 00 00 2b 9b 10 f7 a6 |..... .....+....| 00000010 90 24 ef 3e dd 8e c2 b8 60 a0 10 00 |.$.>....`...| 2023-08-22T11:16:22.0296: Read packet (Decrypted): 00000000 1c |.|

I can provide the full trace.log via PN if needed, but dont like to add it here

[sijms]

I find the solution but i can't test it so i will finish and make commit then i will tell you to test it

[sijms]

I make a commit that contain code for reading TTC 28 code . would you please load this code and test it

[Tommi2Day]

Unfortunately, i got the same error again. Tested with github.com/sijms/go-ora/v2 v2.7.16-0.20230822215245-d2807e91cf11

alter session set container=SQLDEPLOY 2023-08-23T11:46:47.3687: Write packet (Decrypted): 00000000 03 5e 00 02 80 21 00 01 01 25 01 01 0d 00 00 00 |.^...!...%......| 00000010 00 04 3f ff ff ff 00 00 00 00 00 00 00 00 00 00 |..?.............| 00000020 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| 00000030 00 25 61 6c 74 65 72 20 73 65 73 73 69 6f 6e 20 |.%alter session | 00000040 73 65 74 20 63 6f 6e 74 61 69 6e 65 72 3d 53 51 |set container=SQ| 00000050 4c 44 45 50 4c 4f 59 01 01 01 01 00 00 00 00 00 |LDEPLOY.........| 00000060 00 00 02 80 00 00 00 00 |........| 2023-08-23T11:46:47.3688: Write packet: 00000000 00 00 00 7c 06 00 00 00 00 00 61 75 28 5b 01 7e |...|......au([.~| 00000010 18 dc c5 a3 6f ef 77 32 ed 1c 49 2a 98 88 bc 78 |....o.w2..I*...x| 00000020 9e 8a 48 a1 27 7a d5 f8 3e 61 54 18 d2 84 34 c8 |..H.'z..>aT...4.| 00000030 00 28 34 53 98 43 da 1d 02 d7 ea 79 71 37 ae 6f |.(4S.C.....yq7.o| 00000040 cb 86 cd 01 94 63 b9 bd 01 8e d8 50 fc 6a f4 3d |.....c.....P.j.=| 00000050 0f 4e e8 b9 33 8b 9f 87 5a f7 bb b7 e7 b4 64 d0 |.N..3...Z.....d.| 00000060 68 1b 50 e7 34 f8 8a 9b f1 04 f1 e2 e9 df ed 45 |h.P.4..........E| 00000070 44 4d 23 f2 f7 d2 86 dd 15 99 09 00 |DM#.........| 2023-08-23T11:46:47.3880: Read packet: 00000000 00 00 00 1c 06 20 00 00 00 00 9e 44 e6 98 1a f0 |..... .....D....| 00000010 20 37 f9 ed cd c3 c7 a5 26 6b 10 00 | 7......&k..| 2023-08-23T11:46:47.3881: Read packet (Decrypted): 00000000 1c |.|

[sijms]

sorry I make some mistakes I fix it in last commit

[Tommi2Day]

Yeah, this looks much better. Tested with github.com/sijms/go-ora/v2 v2.7.16-0.20230823173955-f8fb6a9452b4

alter session set container=SQLDEPLOY 2023-08-24T11:37:29.6169: Write packet (Decrypted): 00000000 03 5e 00 02 80 21 00 01 01 25 01 01 0d 00 00 00 |.^...!...%......| 00000010 00 04 3f ff ff ff 00 00 00 00 00 00 00 00 00 00 |..?.............| 00000020 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| 00000030 00 25 61 6c 74 65 72 20 73 65 73 73 69 6f 6e 20 |.%alter session | 00000040 73 65 74 20 63 6f 6e 74 61 69 6e 65 72 3d 53 51 |set container=SQ| 00000050 4c 44 45 50 4c 4f 59 01 01 01 01 00 00 00 00 00 |LDEPLOY.........| 00000060 00 00 02 80 00 00 00 00 |........| 2023-08-24T11:37:29.6169: Write packet: 00000000 00 00 00 7c 06 00 00 00 00 00 60 3d 53 1d 04 ce |...|......=S...| 00000010 75 27 19 f2 d7 06 08 2e 5d 68 2b 8a 8d 22 74 21 |u'......]h+.."t!| 00000020 99 44 7b 63 ec 43 7b 77 da b4 39 4e 50 ab 86 a4 |.D{c.C{w..9NP...| 00000030 2b ad 84 2e 9e e4 8f fb 43 c1 7e da 68 dd 21 27 |+.......C.~.h.!'| 00000040 6b df da 45 7f ff 2c 8f 3c f7 0b 3e df cd ad 95 |k..E..,.<..>....| 00000050 c6 08 85 35 ad 41 5a ad 6f 73 e6 b4 60 7f ed 2f |...5.AZ.os..../| 00000060 65 db 03 49 5e da ef d3 3f e4 34 6b 68 0a cf e9 |e..I^...?.4kh...| 00000070 f8 76 72 e7 07 c8 bd 01 fe c0 09 00 |.vr.........| 2023-08-24T11:37:29.6605: Read packet: 00000000 00 00 00 1c 06 20 00 00 00 00 03 e1 4f f3 9f 53 |..... ......O..S| 00000010 00 5c fc 18 ad 64 a5 d9 ab 6e 10 00 |....d...n..| 2023-08-24T11:37:29.6605: Read packet (Decrypted): 00000000 1c |.| 2023-08-24T11:37:29.6606: TCP Negotiation 2023-08-24T11:37:29.6606: Write packet (Decrypted): 00000000 01 06 00 4f 72 61 63 6c 65 43 6c 69 65 6e 74 47 |...OracleClientG| 00000010 6f 00 |o.| 2023-08-24T11:37:29.6606: Write packet: 00000000 00 00 00 2c 06 00 00 00 00 00 5e 34 f1 b7 78 e4 |...,......^4..x.| 00000010 1a ca c1 1a f5 65 78 60 9c 24 37 62 5c 6f d1 77 |.....ex.$7b\o.w| 00000020 43 e1 7d a2 48 5b 7f de 7b b0 0f 00 |C.}.H[..{...| 2023-08-24T11:37:29.6739: Read packet: 00000000 00 00 00 cc 06 20 00 00 00 00 fa 37 f0 12 19 71 |..... .....7...q| 00000010 56 62 43 e8 78 5c 7c cf f6 91 b8 8a 9b e9 7b 75 |VbC.x\|.......{u| 00000020 72 39 07 42 f6 0c 5e d8 ad 4d ba e9 d5 fd 69 6d |r9.B..^..M....im| 00000030 4c 1b 18 94 f1 57 85 e6 b4 59 98 03 d2 3b e7 9c |L....W...Y...;..| 00000040 98 ef 02 79 58 11 32 37 2c 35 d0 06 29 39 5c c8 |...yX.27,5..)9\.| 00000050 9a fe 9a ab 0a ce 9e 95 7a 82 b7 4b 04 12 e2 45 |........z..K...E| 00000060 25 b3 3a 3e 53 84 7c 30 7b 5b 2b 97 67 c4 d0 28 |%.:>S.|0{[+.g..(| 00000070 19 71 41 31 ca f3 c5 f1 25 0e bb 36 06 57 b9 9c |.qA1....%..6.W..| 00000080 86 2f 37 14 8b c9 c8 6c 14 c6 d8 49 7c ac 6f 6d |./7....l...I|.om| 00000090 4a 6f 45 d0 a5 d3 46 09 4b 90 0d ae cf 04 c1 0b |JoE...F.K.......| 000000a0 3c dc 1d e0 f9 f0 cb a3 75 b4 c1 fa 69 b7 9f 1c |<.......u...i...| 000000b0 19 51 d7 ac 6d 56 7f cf 82 01 c3 4c 8e 6a f0 1e |.Q..mV.....L.j..| 000000c0 ad 0c 97 94 f4 ad 6b c5 ca 20 0c 00 |......k.. ..| 2023-08-24T11:37:29.6739: Read packet (Decrypted): 00000000 01 06 00 78 38 36 5f 36 34 2f 4c 69 6e 75 78 20 |...x86_64/Linux | 00000010 32 2e 34 2e 78 78 00 2e 00 01 00 00 00 64 00 00 |2.4.xx.......d..| 00000020 00 60 01 24 0f 05 0b 0c 03 0c 0c 05 04 05 0d 06 |..$............| 00000030 09 07 08 05 05 05 05 05 0f 05 05 05 05 05 0a 05 |................| 00000040 05 05 05 05 04 05 06 07 08 08 23 47 23 47 08 11 |..........#G#G..| 00000050 23 08 11 41 b0 47 00 83 00 2e 07 d0 03 00 00 00 |#..A.G..........| 00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| 00000070 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| 00000080 00 00 2a 06 01 01 01 6f 07 01 0c 01 01 01 01 01 |..*....o........| 00000090 01 01 7f ff 03 0e 03 03 01 01 ff 01 ff ff 01 0b |................| 000000a0 01 01 ff 01 06 0b e2 01 7f 05 0f 0f 0d 07 02 01 |................| 000000b0 00 01 18 00 7f |.....| 2023-08-24T11:37:29.6739: Server Charset: 46 2023-08-24T11:37:29.6739: Server National Charset: 2000 2023-08-24T11:37:29.6740: Data Type Negotiation 2023-08-24T11:37:29.6741:

[sijms]

is there any error comming or every thing is ok

[Tommi2Day]

No errors so far in my test case. I think its ready to release. THX for this solution