Please see my other blog for Oracle EBusiness Suite Posts - EBMentors

Search This Blog

Note: All the posts are based on practical approach avoiding lengthy theory. All have been tested on some development servers. Please don’t test any post on production servers until you are sure.

Monday, November 18, 2013

Exadata: Tracing Oracle I/O Requests on Exadata DB Nodes

With Oracle Exadata, database IO is handled exclusively by the cellsrv process on storage servers. The database nodes bundle IO requests into iDB messages and transmit these over the infiniband network grid to storage server. To confirm where physical database IO is performed on Oracle Exadata, we can use strace to trace system calls from an Oracle instance process. strace is a tool for tracing system calls and signals . It intercepts and records the system calls made by a running process. strace can print a record of each system call, its arguments, and its return value.

Steps:
1- Logon to Oracle Exadata database node and find the process id of Oracle Process DBWR for any of the instance running.

[root@exadb ~]# ps -ef|grep exadb|grep dbw

oracle    3368     1  0 16:49 ?        00:00:02 ora_dbw0_exadb

2- Attach the process id to the strace and do some data activity from the instance eg; query some table

[root@exadb ~]# strace -c -p 3368
Process 3368 attached - interrupt to quit
^CProcess 3368 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 95.24    0.006923          33       212           sendmsg
  4.76    0.000346           1       243        59 recvmsg
  0.00    0.000000           0        59           poll
  0.00    0.000000           0        14           getrusage
  0.00    0.000000           0        44           times
  0.00    0.000000           0         7         7 semtimedop
------ ----------- ----------- --------- --------- ----------------
100.00    0.007269                   579        66 total
[root@exadb ~]#

The DBWR process used the sendmsg system call to package an IO request, which ships the iDB message over the infiniband network in the case of Exadata and a recvmsg call to receive the data from the storage server.

3- To further drill down you could use the strace without -c option but using -o option to have the output in a trace file.
[root@exadb ~]# strace -o straceout.txt -p 3368
Process 3368 attached - interrupt to quit
^CProcess 3368 detached
[root@exadb ~]# 

In the output (straceout.txt) file examine for the sendmsg and recvmsg calls. You will see like below, observe the IP addresses for the storage servers.

getrusage(RUSAGE_SELF, {ru_utime={0, 309952}, ru_stime={3, 96529}, ...}) = 0
getrusage(RUSAGE_SELF, {ru_utime={0, 309952}, ru_stime={3, 96529}, ...}) = 0
times({tms_utime=30, tms_stime=309, tms_cutime=0, tms_cstime=0}) = 430351253
semtimedop(262146, 0x7fffa4927840, 1, {1, 30000000}) = -1 EAGAIN (Resource temporarily unavailable)
times({tms_utime=30, tms_stime=309, tms_cutime=0, tms_cstime=0}) = 430351356
times({tms_utime=30, tms_stime=309, tms_cutime=0, tms_cstime=0}) = 430351356
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(5)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31d\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\0\0\t\0\0\0", 28}, {"\4\3\2\1\2\16\n\0\370N\226)\0\0\0\0}\341v\1(\r\0\0\0\0\1\0\0105\245\245"..., 64}, {"\4\3\2\1Y\243a\247\35\0\0\0\0\0\1\0\0 \0\0\0\0\0\0\v\10\0\0\5\0\0\0"..., 152}, {"&\242\0\0\0\1\300\0\1\23,\0\0\0\1\4\243a\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 808}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31e\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\1\0\t\0\0\0", 28}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31f\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\2\0\t\0\0\0", 28}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31g\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\3\0\t\0\0\0", 28}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31h\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\4\0\t\0\0\0", 28}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31i\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\5\0\t\0\0\0", 28}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31j\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\6\0\t\0\0\0", 28}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(52953), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1]^\207\0\0\0\0\0MRON\4\3\0\0\0\0\0\0}\341v\1k9\333\25"..., 76}, {"\2\31k\271d\271\0\0\0\4\0\0\230\0\0\0\0 \0\0\0\0\7\0\t\0\0\0", 28}, {"\1\0\0\0\33<\212Rg\23\0\0\226\7\300\0e\20,\0\0\0\0\0\t\0\24\0\0\0\0\0"..., 1024}], msg_controllen=0, msg_flags=0}, 0) = 1128
poll([{fd=26, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}, {fd=25, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}, {fd=27, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 3, 16) = 1 ([{fd=25, revents=POLLIN|POLLRDNORM}])
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0k9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0l9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0n9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0o9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0p9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0q9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(35396), sin_addr=inet_addr("192.168.26.20")}, msg_iov(3)=[{"\4\3\2\1\5\n\f\0\0\0\0\0MRON\4\3\0\0\0\0\0\0\212\377U=\0\0\0\0"..., 76}, {"\1\0\20\0\0\0\0\0X\0\0\0\377\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0", 28}, {"\4\3\2\1\v\0\0\0}\341v\1\0\0\0\0r9\0\0\0\0\0\0gv\226\0\0\0\0\0"..., 576}], msg_controllen=0, msg_flags=0}, 0) = 192


No comments: