[mod_python] mod_python errors

Clodoaldo clodoaldo.pinto.neto at gmail.com
Sat Apr 5 19:05:45 EDT 2008


Three errors have been happening in an application using mod_python.

Configuration:
Fedora Core 6. This server does not have mod_wsgi installed.
# uname -a
Linux myserver.net 2.6.22.14-72.fc6 #1 SMP Wed Nov 21 14:10:25 EST
2007 x86_64 x86_64 x86_64 GNU/Linux

Python 2.4.4
# ldd /usr/lib64/libpython2.4.so
        libpthread.so.0 => /lib64/libpthread.so.0 (0x0000003751e00000)
        libdl.so.2 => /lib64/libdl.so.2 (0x00000032d1000000)
        libutil.so.1 => /lib64/libutil.so.1 (0x00000032d8800000)
        libm.so.6 => /lib64/libm.so.6 (0x00000032d1400000)
        libc.so.6 => /lib64/libc.so.6 (0x00000032d0c00000)
        /lib64/ld-linux-x86-64.so.2 (0x0000555555554000)

mod_python 3.3.0b
# ldd /usr/lib64/httpd/modules/mod_python.so
        libpthread.so.0 => /lib64/libpthread.so.0 (0x00002aaaaae07000)
        libdl.so.2 => /lib64/libdl.so.2 (0x00002aaaab021000)
        libutil.so.1 => /lib64/libutil.so.1 (0x00002aaaab225000)
        libm.so.6 => /lib64/libm.so.6 (0x00002aaaab429000)
        libc.so.6 => /lib64/libc.so.6 (0x00002aaaab6ac000)
        /lib64/ld-linux-x86-64.so.2 (0x0000555555554000)

[Sat Apr 05 01:32:13 2008] [notice] Digest: generating secret for
digest authentication ...
[Sat Apr 05 01:32:13 2008] [notice] Digest: done
[Sat Apr 05 01:32:13 2008] [notice] mod_python: Creating 8 session
mutexes based on 256 max processes and 0 max threads.
[Sat Apr 05 01:32:13 2008] [notice] mod_python: using mutex_directory /tmp
[Sat Apr 05 01:32:13 2008] [notice] Apache/2.2.6 (Unix) DAV/2
PHP/5.1.6 mod_python/3.3.0b Python/2.4.4 mod_ssl/2.2.6 OpenSSL/0.9.8b
mod_perl/2.0.2 Perl/v5.8.8 configured -- resuming normal operations

# httpd -V
Server version: Apache/2.2.6 (Unix)
Server built:   Sep 18 2007 11:25:59
Server's Module Magic Number: 20051115:5
Server loaded:  APR 1.2.7, APR-Util 1.2.8
Compiled using: APR 1.2.7, APR-Util 1.2.8
Architecture:   64-bit
Server MPM:     Prefork
  threaded:     no
    forked:     yes (variable process count)
Server compiled with....
 -D APACHE_MPM_DIR="server/mpm/prefork"
 -D APR_HAS_SENDFILE
 -D APR_HAS_MMAP
 -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
 -D APR_USE_SYSVSEM_SERIALIZE
 -D APR_USE_PTHREAD_SERIALIZE
 -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
 -D APR_HAS_OTHER_CHILD
 -D AP_HAVE_RELIABLE_PIPED_LOGS
 -D DYNAMIC_MODULE_LIMIT=128
 -D HTTPD_ROOT="/etc/httpd"
 -D SUEXEC_BIN="/usr/sbin/suexec"
 -D DEFAULT_PIDLOG="logs/httpd.pid"
 -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
 -D DEFAULT_LOCKFILE="logs/accept.lock"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D AP_TYPES_CONFIG_FILE="conf/mime.types"
 -D SERVER_CONFIG_FILE="conf/httpd.conf"

The first error is already described in this thread:
http://www.modpython.org/pipermail/mod_python/2007-June/023795.html

It is also commented in these threads:
http://groups.google.co.uk/group/webpy/browse_thread/thread/4c5f2c76b749eb4e
http://bytes.com/forum/thread40318.html

[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]
ServerName: 'example.com', referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]
DocumentRoot: '/var/www/html/example.com', referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174] URI:
'/_pesquisa', referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174] Location:
None, referer: http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174] Directory:
'/var/www/html/example.com/', referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174] Filename:
'/var/www/html/example.com/_pesquisa.py', referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174] PathInfo:
'', referer: http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174] Traceback
(most recent call last):, referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1537, in HandlerDispatch\n    default=default_handler, arg=req,
silent=hlist.silent), referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1229, in _process_target\n    result = _execute_target(config, req,
object, arg), referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1128, in _execute_target\n    result = object(arg), referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/home/carroarodo/mod/_publisher.py", line 5, in handler\n    return
publisher.handler(req), referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/usr/lib64/python2.4/site-packages/mod_python/publisher.py", line
213, in handler\n    published = publish_object(req, object), referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/usr/lib64/python2.4/site-packages/mod_python/publisher.py", line
424, in publish_object\n    req.form = util.FieldStorage(req,
keep_blank_values=1), referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]   File
"/usr/lib64/python2.4/site-packages/mod_python/util.py", line 225, in
__init__\n    pairs = parse_qsl(req.read(clen), keep_blank_values),
referer: http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
[Sat Apr 05 15:19:51 2008] [error] [client 200.147.229.174]
SystemError: Objects/stringobject.c:3515: bad argument to internal
function, referer:
http://example.com/?estado_sigla=Brasil&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0

The second is more frequent:

[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] mod_python
(pid=326, interpreter='example.com', phase='PythonHandler',
handler='/home/carroarodo/mod/_publisher.py'): Application error,
referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] ServerName:
'example.com', referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] DocumentRoot:
'/var/www/html/example.com', referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] URI:
'/_pesquisa', referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] Location:
None, referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] Directory:
'/var/www/html/example.com/', referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] Filename:
'/var/www/html/example.com/_pesquisa.py', referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] PathInfo: '',
referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] Traceback
(most recent call last):, referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1537, in HandlerDispatch\n    default=default_handler, arg=req,
silent=hlist.silent), referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1229, in _process_target\n    result = _execute_target(config, req,
object, arg), referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1128, in _execute_target\n    result = object(arg), referer:
http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/home/carroarodo/mod/_publisher.py", line 5, in handler\n    return
publisher.handler(req), referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/usr/lib64/python2.4/site-packages/mod_python/publisher.py", line
213, in handler\n    published = publish_object(req, object), referer:
http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/usr/lib64/python2.4/site-packages/mod_python/publisher.py", line
424, in publish_object\n    req.form = util.FieldStorage(req,
keep_blank_values=1), referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196]   File
"/usr/lib64/python2.4/site-packages/mod_python/util.py", line 225, in
__init__\n    pairs = parse_qsl(req.read(clen), keep_blank_values),
referer: http://example.com/
[Sat Apr 05 14:57:49 2008] [error] [client 201.32.1.196] IOError:
Client read error (Timeout?), referer: http://example.com/

This is the access log for the above error:

201.32.1.196 - - [05/Apr/2008:14:57:14 +0000] "POST /_pesquisa
HTTP/1.1" 200 643 "http://example.com/" "Mozilla/4.0 (compatible; MSIE
6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)"
201.32.1.196 - - [05/Apr/2008:14:57:19 +0000] "GET
/?estado_sigla=RJ&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0
HTTP/1.1" 2
00 2773 "http://example.com/" "Mozilla/4.0 (compatible; MSIE 6.0;
Windows NT 5.1; SV1; .NET CLR 1.1.4322)"
201.32.1.196 - - [05/Apr/2008:14:57:21 +0000] "GET
/pub/fotos/0/a/c/0ac0b8a054571a0502f2653620544562769616d8.jpg
HTTP/1.1" 200 6801 "http
://example.com/?estado_sigla=RJ&localidade_id=0&bairro_id=0&fabricante_id=22&modelo_id=0"
"Mozilla/4.0 (compatible; MSIE 6.0; Windows
NT 5.1; SV1; .NET CLR 1.1.4322)"
201.32.1.196 - - [05/Apr/2008:14:56:19 +0000] "POST /_pesquisa
HTTP/1.1" 500 661 "http://example.com/" "Mozilla/4.0 (compatible; MSIE
6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)"
201.32.1.196 - - [05/Apr/2008:14:57:57 +0000] "GET
/ce?i=934&h=sLH2ndocEZ_8EoGtvtsnNA HTTP/1.1" 200 1113 "-" "Mozilla/4.0
(compatible; MS
IE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)"
201.32.1.196 - - [05/Apr/2008:14:58:01 +0000] "GET /login HTTP/1.1"
200 1499 "http://example.com/ce?i=934&h=sLP2ndot1Z_8EoGtvtsnNA" "M
ozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)"


And the third is quite strange:

[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187] PathInfo:
'', referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187] Traceback
(most recent call last):, referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1537, in HandlerDispatch\n    default=default_handler, arg=req,
silent=hlist.silent), referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1229, in _process_target\n    result = _execute_target(config, req,
object, arg), referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/usr/lib64/python2.4/site-packages/mod_python/importer.py", line
1128, in _execute_target\n    result = object(arg), referer:
http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/home/carroarodo/mod/_publisher.py", line 5, in handler\n    return
publisher.handler(req), referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/usr/lib64/python2.4/site-packages/mod_python/publisher.py", line
213, in handler\n    published = publish_object(req, object), referer:
http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/usr/lib64/python2.4/site-packages/mod_python/publisher.py", line
425, in publish_object\n    return
publish_object(req,util.apply_fs_data(object, req.form, req=req)),
referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/usr/lib64/python2.4/site-packages/mod_python/util.py", line 554, in
apply_fs_data\n    return object(**args), referer:
http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187]   File
"/var/www/html/example.com/login.py", line 52, in index\n
_d['mensagem'] += \\, referer: http://example.com/login
[Sat Apr 05 20:58:11 2008] [error] [client 189.69.253.187] TypeError:
unsupported operand type(s) for +=: 'NoneType' and 'str', referer:
http://example.com/login

Access log:
189.27.86.85 - - [05/Apr/2008:20:58:08 +0000] "GET / HTTP/1.1" 200
5739 "http://example.com/" "Mozilla/4.0 (compatible; MSIE 6.0; Windows
NT 5.1; SV1; Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1) ;
FDM; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.04506.648;
.NET CLR 3.5.21022)"

The line it complains about is this:

               _d['mensagem'] += \
                  '<br><br>Você já leu o email enviado para %s ?'\

This line always work except in the above ocasion.

Regards, Clodoaldo Pinto Neto



More information about the Mod_python mailing list