Can't understand this error in gluon/rewrite.py

[Lisandro]

I have the same app installed several times within a web2py instance (running version 2.16.1-stable+timestamp.2017.11.14.05.54.25).

In some of them, this sentence:

URL(c='default', f=f, args=[contenido.id, contenido.slug], extension='', scheme=True, host=current.CONFIG.dominio)

... throws this traceback error:

Traceback (most recent call last):
File "/var/www/medios/gluon/scheduler.py", line 501, in executor result = dumps(_function(*args, **vars))
File "applications/pescaregional/compiled/models.db.py", line 519, in newsletter
File "applications/pescaregional/modules/globales.py", line 938, in enviar_newsletter 'url_noticia': noticia.url() + utm_vars,
File "/var/www/medios/gluon/packages/dal/pydal/objects.py", line 2407, in __call__ return self.method(self.row, *args, **kwargs)
File "applications/pescaregional/compiled/models.db.py", line 295, in
File "applications/pescaregional/modules/virtual_methods.py", line 248, in contenido_url return URL(c='default', f=f, args=[contenido.id, contenido.slug], extension='', scheme=True, host=current.CONFIG.dominio) if f else None
File "/var/www/medios/gluon/html.py", line 391, in URL args, other, scheme, host, port, language=language)
File "/var/www/medios/gluon/rewrite.py", line 197, in url_out function, args, other, scheme, host, port, language)
File "/var/www/medios/gluon/rewrite.py", line 1366, in map_url_out return map.acf()
File "/var/www/medios/gluon/rewrite.py", line 1292, in acf self.omit_acf() # try to omit a/c/f
File "/var/www/medios/gluon/rewrite.py", line 1241, in omit_acf if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications: TypeError: 'in ' requires string as left operand, not long

The problem is solved changing the sentence with this:

URL(c='default', f=f, args=['%s' % contenido.id, '%s' % contenido.slug], extension='', scheme=True, host=current.CONFIG.dominio)

... notice that the args are converted to strings.

But the weird part is that the error only happens in some of the installed apps; and, remember, it's the exact same app installed several times.

First I thought it had something to do with the values stored at "contenido", which is a row from a table. But it happens with any row.

I'm using PostgreSQL 9.3. I've checked the databases' enconding and they all have the same one. I also checked the "contenido" table definition in a couple of dbs (one corresponding to an app that presents the error, and other that doesn't), and they are exactly the same.

What could be the difference that makes gluon/rewrite.py throw the error in some of the apps?

[fiubarc]

Hello,

I think it's more a matter of python language, contenido.id is long type then self.args[0] in 'any string'  raise an exception because, as the message says :

'in ' requires string as left operand, not long

You can do args=['%s' % contenido.id, .... or args=[str(contenido.id), ....





Dont know why in others installed apps works, is really weird


[Lisandro]

Thanks for that fast response.

If the cause of the problem is passing "contenido.id" as int, then the error is even more weird, because my app uses URL like that in several situations, for example:

URL('contenido', 'editar', args=contenido.id)

URL('categoria', 'editar', args=categoria.id)

URL('default', 'index', args=[categoria.id, page_number])

Now that I think it, the error that I reported happens within the scheduler environment.

Could that difference be the reason? Well, even in that case, it wouldn't explain why it works ok in other apps.

[Lisandro]

This problem is getting weirder.

I've found that passing integer numbers as args to URL() helper isn't a problem for web2py. 

I could successfully run some examples using integer and long integers as URL args, and it always works ok. 

In fact, as I stated before, my application uses URL in that way since a long time ago, with no errors.

Even more: in the apps where the code fails, it only fails when it is run from the scheduler, but it works ok if it is run from the controllers.

But, just to remember, it doesn't fail in all the apps, only in some of them. But the apps are all the same, it's the same app installed several times.

A quick resume:

This sentence:

URL('default', f=f, args=[contenido.id, contenido.slug], extension='', scheme=True, host=current.CONFIG.dominio)

 * from a controller, it always runs ok.

 * from the scheduler, it fails in some applications.

The error points to gluon/rewrite.py:

File "applications/pescaregional/modules/virtual_methods.py", line 248, in contenido_url return URL(c='default', f=f, args=[contenido.id, contenido.slug], extension='', scheme=True,host=current.CONFIG.dominio) if f else None

File "/var/www/medios/gluon/html.py", line 391, in URL args, other, scheme, host, port, language=language)
File "/var/www/medios/gluon/rewrite.py", line 197, in url_out function, args, other, scheme, host, port, language)
File "/var/www/medios/gluon/rewrite.py", line 1366, in map_url_out return map.acf()
File "/var/www/medios/gluon/rewrite.py", line 1292, in acf self.omit_acf() # try to omit a/c/f
File "/var/www/medios/gluon/rewrite.py", line 1241, in omit_acf if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications: TypeError: 'in ' requires stringas left operand, not long

I'm a bit lost.

Where else should I look?

[Anthony]

What does your routes.py file look like?

[Lisandro]

This is my routes.py:

# -*- coding: utf-8 -*-

# creates a dictionary that will map each domain with its own app,
# based on the content of a text file called "domains_apps", and also
# a list of all the apps installed
domains = {}
apps = []
_archivo = open('domains_apps', 'r')
_lineas = _archivo.readlines()
_archivo.close()
for _linea in _lineas:
    domain, app = _linea.strip().split('!')
    domains[domain] = app
    if not app in apps:
        apps.append(app)


routers = dict(\
  BASE = dict(\
    default_controller = 'default', \
    default_function = 'index', \
    domains = domains, \
    root_static = ['robots.txt'], \
    map_static = True, \
    exclusive_domain = True, \
  )\
)


routes_onerror = []
for app in apps:
    for code in ['403', '404', '500', '503']:
        routes_onerror.append((r'%s/%s' %(app, code), r'/%s/static/%s.html' %(app, code)))
    routes_onerror.append((r'%s/*' %app, r'/%s/static/500.html' %app))

The file "domains_apps" looks like this:

adn979.com!adn
panel.adn979.com!adn_panel
blogdemedios.com.ar!blogmedios
panel.blogdemedios.com.ar!blogmedios_panel
demo.medios.com.ar!demo
panel.demo.medios.com.ar!demo_panel
diarioprimicia.com.ar!diarioprimicia
panel.diarioprimicia.com.ar!diarioprimicia_panel

Notice each domain has its own app associated. 

This web2py instance is running ~600 apps (that is, 600 copies of the same app).

Do you see something odd here?

In the meantime, I'll verify that all the apps referened in "domains_apps" file are in deed installed apps.

[Leonel Câmara]

Since it only happens with some installations, my guess is that this is happening in the case where this is the only web2py app (not even the admin or welcome is installed). In this case the list of applications is probably a single string instead of a list.

Are you setting routers.BASE.applications somewhere in your routes.py?

Otherwise, I think this is definitely a web2py bug where the default value of routers.BASE.applications which is a string 'ALL' is being passed without being converted to a list of all applications.

[Anthony]

Doesn't look like routers.BASE.applications is set in routes.py, but it appears that somehow in the context of the scheduler, the default value of 'ALL' is not getting converted to a list of apps. It's hard to track down exactly where things are going wrong.

Lisandro, maybe confirm the value of routers.BASE.applications at that point in rewrite.py by printing/logging it.

Anthony

 

[Lisandro]

Thank you all for your help.

I've tried to log the value of routers.BASE.applications, but I'm facing an weird situation:

The traceback shows that the error is at line 1241 of gluon/rewrite.py (the second line):

if self.args:

    if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications:

        self.omit_function = False

First I added some lines in order to log the content of "applications":

if self.args:
    mylog = open('mylog.txt', 'a')
    mylog.write('%s\n' % applications)
    mylog.close()    
    if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications:
        self.omit_function = False

Having made that change, I restarted uwsgi and reproduced the error. Then I checked the log, but I only saw a lot of this:

[regionoeste]
[regionoeste]
[pescaregional]
[pescaregional]
[pescaregional_panel]
[pescaregional_panel]
[blogmedios]
[blogmedios]
[blogmedios]

There was nothing like "ALL" or anything weird. Every logged line is a list of one only app (I think that's because I use exclusive_domain=True, so each app can be accessed only through a specific domain). 

Then I tried to catch the error to log anything that could help, so I did this:

if self.args:
    try:

        if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications:

            self.omit_function = False
    except TypeError:
        mylog = open('mylog.txt', 'a')
        mylog.write('%s\n' % applications)
        mylog.close()

Again, restarted uwsgi and reproduced the error.

To my surprise, nothing was logged (the log file hadn't been even created).

But the scheduler task had indeed failed with this traceback:

File "applications/pescaregional/modules/virtual_methods.py", line 248, in contenido_url return URL(a=current.CONFIG.cliente, c='default', f=f, args=[contenido.id, contenido.slug], extension='', scheme=True, host=current.CONFIG.dominio) if f else None

File "/var/www/medios/gluon/html.py", line 391, in URL args, other, scheme, host, port, language=language)
File "/var/www/medios/gluon/rewrite.py", line 197, in url_out function, args, other, scheme, host, port, language)

File "/var/www/medios/gluon/rewrite.py", line 1366, in map_url_out File "/var/www/medios/gluon/rewrite.py", line 1292, in acf def acf(self):
File "/var/www/medios/gluon/rewrite.py", line 1241, in omit_acf try: TypeError: 'in <string>' requires string as left operand, not long

Notice the traceback is slightly different than the original one.

While the last line of the original traceback showed this:

File "/var/www/medios/gluon/rewrite.py", line 1241, in omit_acf if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications: TypeError: 'in ' requires stringas left operand, not long

... in the last test I did it shows this:

File "/var/www/medios/gluon/rewrite.py", line 1241, in omit_acf try: TypeError: 'in <string>' requires string as left operand, not long

Meaning that the code is indeed running with the try:except block I added, but somehow the error isn't cached, although the scheduler task fails and reports that error :/

Some additional info that worths mention:

• I have a development environment with the exact same software and library versions (nginx, uwsgi, postgres, redis, web2py), but I can't reproduce the error there.
  
  
• My production environment grows automatically: an average of 10 new websites are created per month; each time a new website is created, a scheduler task installs a copy of two web2py applications I developed; at this time, the web2py instance is running about 600 apps. The problem started to happen recently, and I can confirm that it happens in all the new websites, while it doesn't happen in the old ones. Could the problem be related to the amount of installed apps? It shouldn't, right?
  
  
• I can also confirm that nothing was changed, there wasn't any server library update, the application code hasn't changed (it's cloned from a local repository that has had the same version for months).

It's very weird.

In the meantime, I'll make a fix to my app, to pass the args to URL as strings, specially in the cases where the code is run within the scheduler environment. 

Let me know if you notice something or if you can think of any other test I could do.

Thanks a lot!

[Leonel Câmara]

The problems seems to be in the controllers and not in the application list since looking at your logs they seem to be fine.

Notice that "load" does not check if the controllers are coming just with "DEFAULT" string.

https://github.com/web2py/web2py/blob/master/gluon/rewrite.py#L283

Can you log the controllers too?

[Lisandro]

I've modified gluon/rewrite.py to log functions and controllers:

if self.args:
    try:

        mylog = open('mylog.txt', 'a')

        mylog.write('%s %s\n' % (self.functions, self.controllers))
        mylog.close()
    except:
        pass

    if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications:

        self.omit_function = False

In the generated log I don't see anything weird:

set([]) set(['load', 'default', 'app', 'static'])
set([]) set(['load', 'default', 'app', 'static'])
set([]) set(['load', 'default', 'app', 'static'])
set([]) set(['load', 'default', 'app', 'static'])
set([]) set(['default', 'cache', 'afip', 'reportes', 'contrataciones', 'admin', 'paypal', 'errores', 'periodos', 'facturas', 'ws', 'sitios', 'scheduler', 'static', 'mercadopago', 'estadistica', 'notificaciones'])
set([]) set(['default', 'cache', 'afip', 'reportes', 'contrataciones', 'admin', 'paypal', 'errores', 'periodos', 'facturas', 'ws', 'sitios', 'scheduler', 'static', 'mercadopago', 'estadistica', 'notificaciones'])
set([]) set(['default', 'cache', 'afip', 'reportes', 'contrataciones', 'admin', 'paypal', 'errores', 'periodos', 'facturas', 'ws', 'sitios', 'scheduler', 'static', 'mercadopago', 'estadistica', 'notificaciones'])
set([]) set(['default', 'cache', 'afip', 'reportes', 'contrataciones', 'admin', 'paypal', 'errores', 'periodos', 'facturas', 'ws', 'sitios', 'scheduler', 'static', 'mercadopago', 'estadistica', 'notificaciones'])
set([]) set(['default', 'cache', 'afip', 'reportes', 'contrataciones', 'admin', 'paypal', 'errores', 'periodos', 'facturas', 'ws', 'sitios', 'scheduler', 'static', 'mercadopago', 'estadistica', 'notificaciones'])
set([]) set(['default', 'cache', 'afip', 'reportes', 'contrataciones', 'admin', 'paypal', 'errores', 'periodos', 'facturas', 'ws', 'sitios', 'scheduler', 'static', 'mercadopago', 'estadistica', 'notificaciones'])

There is a bunch of that. Notice the function list is always empty, I'm not sure if that's correct (I would say yes, because everything works as expected).

The list of controllers is correct, they correspond to the application running in each case.

Because I have many many applications installed and running, the log file was growing very quickly, so I made a simple modification to the code, to log only when the application was one of the ones throwing the error:

if self.args:
    try:
        if self.application in ('pescaregional', 'experienciasgo'):

            mylog = open('mylog.txt', 'a')

            mylog.write('%s %s\n' % (self.functions, self.controllers))
            mylog.close()
    except:
        pass

    if self.args[0] in self.functions or self.args[0] in self.controllers or self.args[0] in applications:

    self.omit_function = False

The log was the same as the one I showed before.

However, I've noticed that self.application is not set in the scheduler environment, because the logging was done when the requests were made through http, but nothing was logged when the requests came from the scheduler environment.

Anyway, I think this is too much for me. Debugging this is getting hard, as the problem happens only in my production environment, and I don't like very much the idea of changing web2py code of the main instance that is running several apps. Regardless I use uwsgi gracefully reloading, I've done this tests very late at night, when the activity is low, but still I'm afraid of breaking something at production.

For now, I'll just apply a simple patch: whenever I use URL() in the scheduler environment, I'll check that the args are provided as strings.

Thanks a lot for your help!!