search

oracle / odpi

ODPI-C: Oracle Database Programming Interface for Drivers and Applications
https://oracle.github.io/odpi/
Other
268 stars 78 forks source link

Suggestions about debug message format #34

Closed kubo closed 7 years ago

kubo commented 7 years ago

There are suggestions about debug message format: (1) thread ID and (2) date format.

When DPI_DEBUG_LEVEL was set, the following messages were printed on Linux.

ODPI [140274862778112] 2017/09/02 14:13:44.244: ref 0x167c1d0 (dpiPool) -> 1 [NEW]
ODPI [140274862778112] 2017/09/02 14:13:44.282: ref 0x17026b0 (dpiConn) -> 1 [NEW]
ODPI [140274862778112] 2017/09/02 14:13:44.282: ref 0x167c1d0 (dpiPool) -> 2
ODPI [140274862778112] 2017/09/02 14:13:44.282: ref 0x167c1d0 (dpiPool) -> 1
ODPI [140274862778112] 2017/09/02 14:13:44.282: ref 0x16ed170 (dpiVar) -> 1 [NEW]
...

Thread ID

The thread ID 140274862778112 is available to identify a thread but it is a too big number. That's because it is an address of struct pthread in the process, not a thread ID in the OS. If it is a thread ID in the OS, the messages are printed as follows:

ODPI [11318] 2017/09/02 14:36:30.607: ref 0x151a1d0 (dpiPool) -> 1 [NEW]
ODPI [11318] 2017/09/02 14:36:30.696: ref 0x15a06b0 (dpiConn) -> 1 [NEW]
ODPI [11318] 2017/09/02 14:36:30.696: ref 0x151a1d0 (dpiPool) -> 2
ODPI [11318] 2017/09/02 14:36:30.697: ref 0x151a1d0 (dpiPool) -> 1
ODPI [11318] 2017/09/02 14:36:30.697: ref 0x158b170 (dpiVar) -> 1 [NEW]
...

Thread IDs in the OS is retrieved by syscall(SYS_gettid) on Linux.

Thread IDs in the macOS seems to be retrieved by pthread_threadid_np. It is available since OS X 10.6 Snow Leopard. The source of the man page about pthread_threadid_np is here but formatted page could not be found in the apple site.

Date format

I prefer YYYY-MM-DD to YYYY/MM/DD because the former is same with standards. The latter is widely used in Japan. But I don't know whether it is acceptable in other countries. (I have not lived outside of Japan.)

kubo commented 7 years ago

It may be better to use "0x%lx" to print thread id on macOS because dtruss -l prints thread ids as hexadecimal as follows. (8900 == 0x22c4)

$ curl -O https://raw.githubusercontent.com/kubo/test-code-collection/d510543/unix/get_thread_id.c
$ cc -o get_thread_id get_thread_id.c
$ sudo dtruss -l ./get_thread_id 

pthread_self = 0x7fff73341000
thread_id = 8900
    PID/THRD  SYSCALL(args)          = return
  845/0x22c4:  thread_selfid(0x0, 0x0, 0x0)      = 8900 0
  845/0x22c4:  open(".\0", 0x0, 0x1)         = 3 0
  845/0x22c4:  fstat64(0x3, 0x7FFF55DBE760, 0x1)         = 0 0
...

When thread ids in odpi debug output are formatted as hexadecimal number, it is easy to compare them with thread ids in dtruss output.

anthony-tuininga commented 7 years ago

Thanks, Kubo. The note about date format is well taken. I can make that change. The call to get the thread id on Linux can be implemented easily enough as well as the one for macOS. I avoided them to this point to ensure I didn't have any problems with portability, but it would be nicer to have the OS specific details available. @cjbj, do you have a comment on the macOS comment regarding dtruss? Or any of the other suggestions made here?

anthony-tuininga commented 7 years ago

The date format and thread id format have been changed as suggested. On macOS I did not change the thread id format to hexadecimal -- at least not yet. I'll wait to see if there are other cases where the decimal representation is preferred -- and then decide whether to change it wholesale to hexadecimal or allow for both options in some way. Reasonable?

kubo commented 7 years ago

There may be other cases where decimal is preferred as you wrote. I don't know tools on macOS other than dtruss. I have not used GUI developer tools on macOS.

Decimal representation on macOS is okay for me. It is easy to convert decimals to hexadecimals and vice versa.

FYI: strace -f on Linux printed decimal thread ids as follows.

$ wget https://raw.githubusercontent.com/kubo/test-code-collection/0ca71eb/unix/get_thread_id.c
$ cc -o get_thread_id get_thread_id.c -pthread
$ strace -f -e trace=gettid -o strace.log ./get_thread_id
main : pthread_self = 139933633832704
main : thread_id = 15626
child: pthread_self = 139933625562880
child: thread_id = 15627
$ cat strace.log
15626 gettid()                          = 15626
15627 gettid()                          = 15627
15627 +++ exited with 0 +++
15626 +++ exited with 0 +++
anthony-tuininga commented 7 years ago

In that case we'll close this. If it becomes clear later on that hexadecimal representation is more useful in certain cases, please open a new issue. Thanks!