I have a Django app that connects to Oracle. Every 10 refreshes or so, regardless of what page, it gives an error. First time after restart an ORA-03113 and every subsequent errors ORA-03135.
I have checked to alert.log and listener.log on the database side and can't find anything about this session terminating in the log file.
I've edited site-packages/django/db/init.py and put an try/except around close_if_unusable_or_obsolete. The page does not give an error anymore, and in the logfile no ORA error but I still see the SIGPIPE error.
My guess : Django thinks there is still a connection and tries to close (close_if_unusable_or_obsolete) it but on the Oracle side the connection does not exist. The first ORA-03113 does not result in a record in the listener.log, so it seems it does not even reach the Database server. After the modification in the init.py the result page is correct. So the query for building up the page is successful. It seems to be a connection for administrative purposes of some kind.
I'm lost, does anyone have an idea how to find this error?
cx_oracle==5.1.3
Django==1.8.3
Oracle Client : instantclient-basic-linux.x64-12.1.0.2.0
Database version : 11.2.0.3.0
uwsgi_error.log
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/django/core/handlers/wsgi.py", line 177, in __call__
signals.request_started.send(sender=self.__class__, environ=environ)
File "/usr/lib/python2.7/site-packages/django/dispatch/dispatcher.py", line 189, in send
response = receiver(signal=self, sender=sender, **named)
File "/usr/lib/python2.7/site-packages/django/db/__init__.py", line 64, in close_old_connections
conn.close_if_unusable_or_obsolete()
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 403, in close_if_unusable_or_obsolete
self.close()
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 198, in close
self._close()
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 152, in _close
return self.connection.close()
File "/usr/lib/python2.7/site-packages/django/db/utils.py", line 98, in __exit__
six.reraise(dj_exc_type, dj_exc_value, traceback)
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 152, in _close
return self.connection.close()
django.db.utils.OperationalError: ORA-03113: end-of-file on communication channel
Process ID: 10345
Session ID: 195 Serial number: 54225
[pid: 30|app: 0|req: 1/4] 123.123.123.123 () {46 vars in 1024 bytes} [Fri May 27 15:58:34 2016] GET /admin/ => generated 0 bytes in 8 msecs (HTTP/1.1 500) 0 headers in 0 bytes (0 switches on core 0)
[pid: 28|app: 0|req: 4/5] 123.123.123.123 () {46 vars in 1024 bytes} [Fri May 27 15:58:38 2016] GET /admin/ => generated 31712 bytes in 291 msecs (HTTP/1.1 200) 6 headers in 251 bytes (1 switches on core 0)
[pid: 28|app: 0|req: 5/6] 123.123.123.123 () {46 vars in 1024 bytes} [Fri May 27 15:58:39 2016] GET /admin/ => generated 31712 bytes in 276 msecs (HTTP/1.1 200) 6 headers in 251 bytes (1 switches on core 0)
[pid: 28|app: 0|req: 6/7] 123.123.123.123 () {46 vars in 1024 bytes} [Fri May 27 15:58:40 2016] GET /admin/ => generated 31712 bytes in 288 msecs (HTTP/1.1 200) 6 headers in 251 bytes (1 switches on core 0)
[pid: 30|app: 0|req: 2/8] 123.123.123.123 () {46 vars in 1024 bytes} [Fri May 27 15:58:40 2016] GET /admin/ => generated 31712 bytes in 608 msecs (HTTP/1.1 200) 6 headers in 251 bytes (1 switches on core 0)
Fri May 27 15:58:41 2016 - SIGPIPE: writing to a closed pipe/socket/fd (probably the client disconnected) on request /admin/ (ip 131.180.77.1) !!!
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/django/core/handlers/wsgi.py", line 177, in __call__
signals.request_started.send(sender=self.__class__, environ=environ)
File "/usr/lib/python2.7/site-packages/django/dispatch/dispatcher.py", line 189, in send
response = receiver(signal=self, sender=sender, **named)
File "/usr/lib/python2.7/site-packages/django/db/__init__.py", line 64, in close_old_connections
conn.close_if_unusable_or_obsolete()
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 403, in close_if_unusable_or_obsolete
self.close()
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 198, in close
self._close()
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 152, in _close
return self.connection.close()
File "/usr/lib/python2.7/site-packages/django/db/utils.py", line 98, in __exit__
six.reraise(dj_exc_type, dj_exc_value, traceback)
File "/usr/lib/python2.7/site-packages/django/db/backends/base/base.py", line 152, in _close
return self.connection.close()
django.db.utils.OperationalError: ORA-03135: connection lost contact
Process ID: 10345
Session ID: 195 Serial number: 54225
SQL*Net trace file contains:
(4043057216) [31-MAY-2016 15:18:51:303] nioqsn: entry
(4043057216) [31-MAY-2016 15:18:51:304] nioqsn: exit
(4043057216) [31-MAY-2016 15:18:51:304] nioqrc: entry
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_bsd: entry
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_bsd: tot=0, plen=13.
(4043057216) [31-MAY-2016 15:18:51:304] nttfpwr: entry
(4043057216) [31-MAY-2016 15:18:51:304] nttfpwr: socket 29 had bytes written=13
(4043057216) [31-MAY-2016 15:18:51:304] nttfpwr: exit
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_bsd: packet dump
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_bsd: 00 0D 00 00 06 00 00 00 |........|
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_bsd: 00 00 03 0F 0F |..... |
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_bsd: exit (0)
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_brc: entry: oln/tot=0
(4043057216) [31-MAY-2016 15:18:51:304] nttfprd: entry
(4043057216) [31-MAY-2016 15:18:51:304] ntt2err: entry
(4043057216) [31-MAY-2016 15:18:51:304] ntt2err: Read unexpected EOF ERROR on 29
(4043057216) [31-MAY-2016 15:18:51:304] ntt2err: exit
(4043057216) [31-MAY-2016 15:18:51:304] nttfprd: exit
(4043057216) [31-MAY-2016 15:18:51:304] nserror: entry
(4043057216) [31-MAY-2016 15:18:51:304] nserror: nsres: id=0, op=68, ns=12537, ns2=12560; nt[0]=507, nt[1]=0, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0
(4043057216) [31-MAY-2016 15:18:51:304] nsbasic_brc: exit: oln=0, dln=0, tot=0, rc=-1
(4043057216) [31-MAY-2016 15:18:51:304] nioqer: entry
(4043057216) [31-MAY-2016 15:18:51:304] nioqer: incoming err = 12151
(4043057216) [31-MAY-2016 15:18:51:304] nioqce: entry
(4043057216) [31-MAY-2016 15:18:51:304] nioqce: exit
(4043057216) [31-MAY-2016 15:18:51:304] nioqer: returning err = 3113
(4043057216) [31-MAY-2016 15:18:51:304] nioqer: exit
(4043057216) [31-MAY-2016 15:18:51:304] nioqrc: exit
(4043057216) [31-MAY-2016 15:18:51:304] nioqds: entry
(4043057216) [31-MAY-2016 15:18:51:304] nioqds: disconnecting...
Incomming Error ORA-12151: TNS:received bad packet type from network layer
EDIT Response to Titus
SELECT PROFILE, LIMIT FROM DBA_PROFILES WHERE RESOURCE_NAME = 'IDLE_TIME'; and:
DEFAULT UNLIMITED
SELECT PROFILE FROM DBA_USERS WHERE USERNAME = 'DJANGO_USER';
DEFAULT
I don't use TNSNAMES.ORA or SQLNET.ORA
This is the workaround that worked for me:
# wsgi.py
from django.db import connection
from uwsgidecorators import postfork
@postfork
def reconnect_to_db():
print "RECONNECT TO DB!"
connection.connect()
For some reason, the uwsgi workers need to be manually connected postfork
, or the first query of every worker would fail.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With