Note: I've replaced IP addresses, database names, and server users with examples. That shouldn't affect anything.
The Setup
I've installed unixODBC (yum install unixODBC) and IBM's official iSeries ODBC driver (yum install ibm-iaccess-1.1.0.5-1.0.x86_64.rpm, RPM downloaded from IBM's logged-in areas). The installation successfully added the drivers to /etc/odbcinst.ini:
[IBM i Access ODBC Driver]
Description = IBM i Access for Linux ODBC Driver
Driver = /opt/ibm/iaccess/lib/libcwbodbc.so
Setup = /opt/ibm/iaccess/lib/libcwbodbcs.so
Driver64 = /opt/ibm/iaccess/lib64/libcwbodbc.so
Setup64 = /opt/ibm/iaccess/lib64/libcwbodbcs.so
Threading = 0
DontDLClose = 1
UsageCount = 1
[IBM i Access ODBC Driver 64-bit]
Description = IBM i Access for Linux 64-bit ODBC Driver
Driver = /opt/ibm/iaccess/lib64/libcwbodbc.so
Setup = /opt/ibm/iaccess/lib64/libcwbodbcs.so
Threading = 0
DontDLClose = 1
UsageCount = 1
The referenced library files do exist, and they are correctly linked (checked via ldd, no missing links).
My ~/.odbc.ini file looks like this:
[Foo]
Driver = IBM i Access ODBC Driver
DATABASE = FooDB
SYSTEM = 123.45.67.8
HOSTNAME = 123.45.67.8
PORT = 446
PROTOCOL = TCPIP
The Problem
When I run isql Foo USER PASSWORD -v, I get this output after roughly a minute or so:
user@example.com [~]# isql FooDB USER PASSWORD -v
[08S01][unixODBC]
[ISQL]ERROR: Could not SQLConnect
Troubleshooting
Sounds like it's timing out, right?
ping 123.45.67.8 returns:
user@example.com [~]# ping 123.45.67.8
PING 123.45.67.8 (123.45.67.8) 56(84) bytes of data.
64 bytes from 123.45.67.8: icmp_seq=1 ttl=63 time=29.8 ms
64 bytes from 123.45.67.8: icmp_seq=2 ttl=63 time=29.8 ms
64 bytes from 123.45.67.8: icmp_seq=3 ttl=63 time=29.8 ms
64 bytes from 123.45.67.8: icmp_seq=4 ttl=63 time=31.0 ms
64 bytes from 123.45.67.8: icmp_seq=5 ttl=63 time=29.9 ms
telnet 123.45.67.8 446 returns:
user@example.com [~]# telnet 123.45.67.8 446
Trying 123.45.67.8...
Connected to 123.45.67.8.
Escape character is '^]'.
foobar
^]
telnet> quit
Connection closed.
Enabling the ODBC log with Trace and TraceFile in /etc/odbcinst.ini produces output like this:
[ODBC][22093][1454628360.104274][__handles.c][450]
Exit:[SQL_SUCCESS]
Environment = 0x13a4750
[ODBC][22093][1454628360.104316][SQLAllocHandle.c][364]
Entry:
Handle Type = 2
Input Handle = 0x13a4750
[ODBC][22093][1454628360.104339][SQLAllocHandle.c][482]
Exit:[SQL_SUCCESS]
Output Handle = 0x13a5080
[ODBC][22093][1454628360.104363][SQLConnect.c][3614]
Entry:
Connection = 0x13a5080
Server Name = [FooDB][length = 4 (SQL_NTS)]
User Name = [USER][length = 7 (SQL_NTS)]
Authentication = [*******][length = 7 (SQL_NTS)]
UNICODE Using encoding ASCII 'ISO8859-1' and UNICODE 'UCS-2LE'
DIAG [08S01]
[ODBC][22093][1454628423.118602][SQLConnect.c][3982]
Exit:[SQL_ERROR]
[ODBC][22093][1454628423.118628][SQLError.c][430]
Entry:
Connection = 0x13a5080
SQLState = 0x7fff9a5bd7b0
Native = 0x7fff9a5bd5a8
Message Text = 0x7fff9a5bd5b0
Buffer Length = 500
Text Len Ptr = 0x7fff9a5bd5ae
[ODBC][22093][1454628423.118656][SQLError.c][467]
Exit:[SQL_SUCCESS]
SQLState = 08S01
Native = 0x7fff9a5bd5a8 -> 10060
Message Text = [[unixODBC]]
[ODBC][22093][1454628423.118685][SQLError.c][430]
Entry:
Connection = 0x13a5080
SQLState = 0x7fff9a5bd7b0
Native = 0x7fff9a5bd5a8
Message Text = 0x7fff9a5bd5b0
Buffer Length = 500
Text Len Ptr = 0x7fff9a5bd5ae
[ODBC][22093][1454628423.118704][SQLError.c][467]
Exit:[SQL_NO_DATA]
[ODBC][22093][1454628423.118722][SQLError.c][510]
Entry:
Environment = 0x13a4750
SQLState = 0x7fff9a5bd7b0
Native = 0x7fff9a5bd5a8
Message Text = 0x7fff9a5bd5b0
Buffer Length = 500
Text Len Ptr = 0x7fff9a5bd5ae
[ODBC][22093][1454628423.118739][SQLError.c][547]
Exit:[SQL_NO_DATA]
[ODBC][22093][1454628423.118765][SQLFreeHandle.c][279]
Entry:
Handle Type = 2
Input Handle = 0x13a5080
[ODBC][22093][1454628423.118784][SQLFreeHandle.c][330]
Exit:[SQL_SUCCESS]
[ODBC][22093][1454628423.118827][SQLFreeHandle.c][212]
Entry:
Handle Type = 1
Input Handle = 0x13a4750
It successfully allocates a handle, then it tries to connect to the database, fails with a generic SQL_ERROR, tries to do something with the error (not sure what?), and then deallocates the handle.
My last resort was to check the network traffic directly. Here's the initial test, using telnet:
[root@host /opt/ibm/iaccess]# tshark -i tun0 -x
Running as user "root" and group "root". This could be dangerous.
Capturing on tun0
0.000000000 10.10.1.10 -> 123.45.67.8 TCP 60 42054 > ddm-rdb [SYN] Seq=0 Win=13660 Len=0 MSS=1366 SACK_PERM=1 TSval=1992917110 TSecr=0 WS=128
...PACKETS...
2.316931937 10.10.1.10 -> 123.45.67.8 TCP 60 42054 > ddm-rdb [PSH, ACK] Seq=1 Ack=1 Win=13696 Len=8 TSval=1992919427 TSecr=4147650000
0000 45 10 00 3c f1 b3 40 00 40 06 73 d2 0a 0a 01 0a E..<..@.@.s.....
0010 ac 10 1e 02 a4 46 01 be e0 f5 71 c8 1d a8 3b 71 .....F....q...;q
0020 80 18 00 6b f5 9b 00 00 01 01 08 0a 76 c9 89 83 ...k........v...
0030 f7 38 1d d0 66 6f 6f 62 61 72 0d 0a .8..foobar..
...PACKETS...
We see some TCP packets, one of which contains foobar, just as we expected.
Now, here's the test with isql:
[root@host /opt/ibm/iaccess]# tshark -i tun0 -x
Running as user "root" and group "root". This could be dangerous.
Capturing on tun0
^C0 packets captured
No traffic!?
Honestly, I'm a bit stuck here. Not sure what to try next. Any thoughts on what could be going wrong, or how to troubleshoot this difficult situation?
Note that the server setup itself is fine. I'm able to connect without a problem using IBM's iSeries ODBC drivers for Windows.
