Need help to debug this error when using URL from gluon/html.py

[Lisandro]

Hi there!

I have a web2py application running, it's been running for a long time, it is a website that serves hundreds of thousands of visits per day, and everything works really good.

However, everyonce in a while (let's say, every 3-4 days) an error ticket is generated with this traceback:

Traceback (most recent call last): 

File "/var/www/medios/gluon/restricted.py", line 227, in restricted exec ccode in environment 

File "applications/website/compiled/views.lista.html.py", line 971, 

in File "/var/www/medios/gluon/html.py", line 387, in URL other += '?%s' % urllib.urlencode(list_vars) 

File "/usr/lib/python2.7/urllib.py", line 1332, in urlencode v = quote_plus(str(v)) 

UnicodeEncodeError: 'ascii' codec can't encode character u'\xed' in position 5: ordinal not in range(128)

The code portion of my "compiled/views.lista.html.py" involved in the error is the call to this function get_url(page), used to create a paginator in the view:

def get_url(page, arg_index):
    args = request.args or []
    if len(args) < (arg_index + 1):
        args.append(None)
    args[arg_index] = pagina
    try:
        return URL(args=args, vars=request.vars)
    except:
        return URL(args=args)

As you see, I put a try: except block there, because I thought maybe the request.vars had something to do with it.

But the error keeps triggering every 3-4 days, and I don't know how to debug it, or where to start.

Of course, I've hit the application with every possible combination of request.vars and request.args, but I can't trigger the error.

Can I do anything else to avoid the error?

Thanks in advance!

[Anthony]

Which line is 971? Are you sure you re-compiled the app after making the code change?

[Lisandro]

Thanks for the quick answer.

Yes, I have automated my app with a function; it sets the app in mantainance mode (message for the public), updates the code from repository, compiles the app, restarts uwsgi, and turns off mantainance mode. 

Just in case, I've just checked and it is running compiled.

Line 917 is the call to get_url() function.

That line is not in the compiled view, but within a module.

The view just renders my pagination object, so it just does {{=pagination.html()}}

The pagination object is defined within a module, and the line 917 is the one calling to get_url().

This is a resume of my Pagination object:

class Pagination(object):
    def __init__(self, cpp, total, pagina, arg_index=0):
        # ... initializations

    def get_url(self, page):
        request = current.request
        args = request.args or []
        while len(args) < (self.arg_index + 1):
            args.append(None)
        args[self.arg_index] = page
        try:

            return URL(args=args, vars=request.vars)
        except:
            return URL(args=args)

    def html(self):
        result = ''
        for e in range(1, self.paginas + 1):
            result += '<a href="%s">%s</a>' % (self.get_url(e), e)
        return XML(result)

The thing is t hat I've hit the URL with any probable combination of args and vars, but I cannot reproduce the error.

Does the ticket store info about the content of vars and args when the error triggered?

I'm sending tickets2email, so I don't conserve the original ticket, but If I could find that info in the ticket, I guess I could disable tickets2email in scheduler and wait for the error to appear again.

[Dave S]

On Tuesday, December 20, 2016 at 10:33:18 AM UTC-8, Lisandro wrote:

 

[...]

Does the ticket store info about the content of vars and args when the error triggered?

I'm sending tickets2email, so I don't conserve the original ticket, but If I could find that info in the ticket, I guess I could disable tickets2email in scheduler and wait for the error to appear again.

Generally, the vars are not shown in the ticket, but why not just call the logger at that point?

The error seems to be unicode (UTF-8, probably) leaking into a URL, and aren't URLs supposed to be ASCII, and special characters are to be escaped (usually as "%20" and the like)?

/dps

[Anthony]

The traceback refers to line 971 in the compiled view (not in a module), indicating a call to the URL() function on that line.

[Pbop]

Issue appears to have come up a few times on stack overflow. 

http://stackoverflow.com/questions/9942594/unicodeencodeerror-ascii-codec-cant-encode-character-u-xa0-in-position-20/9942885

[Lisandro]

Thank you all for the help.

@Anthony, sorry my ignorance, I was looking in the wrong place (looking in the module, asuming the error was triggered there).

Considering your answer and the traceback error, I say "ok, the error is triggered from the view, in the line 917".

But how do I know which is that line if the view is compiled?

I've opened the compiled view with an editor, and went to the 917 line. I don't know if that make sense, but in that line I've found a closing </div> tag... :/

Does it make any sense?

@Dave, I can't use the logger here.

The thing is that the app is actually installed several times (within the same web2py installation), and each app instance is serving a website. 

All the websites are running in production, and among all, they serve around 150k visits per day. 

So in order to try anything, I have to make the change, push it to the repository, and update all the websites.

The error is not a big deal. As you see, there is **a lot** of requests per day, and the error appears every 3-4 days.

[Anthony]

Note, it is line 971, not 917. In the admin app, you can view the Python code of the compiled view in the error ticket.

Anthony

[Lisandro]

Hi there, sorry for the delay, I was waiting for the error to occur.

Today the error triggered again, and I had disabled tickets2email, so I have the ticket, but it doesn't show any code, its odd.

Here is a screen capture of the error ticket detail.

Not sure if a screen capture is the best way, but I wanted to include everything:

Notice that the code part for the compiled view is empty :/

Also, it's not the 971 line, because this error is triggered from a different view that the one I was talking about before. But it's the exact same error, triggering "randomly" every 3-4 days.

It's not a big deal, but I'm wondering how is the error triggered. I'll keep collecting more of these tickets in the following days. Any observation will be appreciated. 

Thanks as always!

[Dave S]

On Thursday, December 22, 2016 at 8:32:16 AM UTC-8, Lisandro wrote:

Hi there, sorry for the delay, I was waiting for the error to occur.

Today the error triggered again, and I had disabled tickets2email, so I have the ticket, but it doesn't show any code, its odd.

Using my magnifying glass, I think I see that there's a Unicode character in the location variable, between "con" and "sus".  Unicode is not allowed in URLs; did you run an escape tool over it?

/dps

[Lisandro]

Sorry about that, the image quality was reduced after uploading it.

Here I made a new screen capture and uploaded it to my drive account, so It's full quality:

https://drive.google.com/file/d/0B0y0m_8LgjGIT3hCU000T0hQamM/view?usp=sharing

But the character you noticed was just some noise in the image.

Just to add something that could be relevant: I use IS_SLUG validator in order to generate a unique slug and store it in a database record. Then, I use it as an argument of URL(), to construct the url of an article. 

I think that shouldn't cause any trouble, but who knows.. ¿maybe some unicode character is leaking into the slug? It shouldn't be the case, because if it was, then the error would be raised constantly, but it is sporadic :/

[Anthony]

Looks like in your call to URL, the vars dictionary includes:

'title': u'Eva de Dominici pos\xf3 como una chica Guess y cont\xf3 sus tips beauty'

Notice that the title is a unicode object. If the title is the only item that might be unicode, you can simply encode it before passing it to the URL() function:

URL(..., vars=dict(..., title=unicode(title).encode('utf8')))

If other items in the query string might also end up as unicode, you should loop through and encode everything.

Anthony

[Lisandro]

Thanks for pointing out that part Anthony. 

I see that there is a 'title' key in the list_vars, but those vars are related to urllib. 

I mean, how do they arrive as keys to that function? I can't figure it out. 

In the ticket details, when I click the "code" button related to my view, it shows an empty space:

So, I'm stucked trying to figure out which line of my code is the one triggering the error.

I've searched and reviewed every "title" occurence in my code, but it's never used as a query var for URL.

Anyway, please let me know if this problem is very app specific, and I will no longer bother here :P

Meanwhile, I'll keep collecting more of these tickets.

Thank you very much!

Regards,

Lisandro.

[Anthony]

I see that there is a 'title' key in the list_vars, but those vars are related to urllib.

list_vars is a local variable within web2py's URL() function -- it contains the keys/values passed in via the "vars" argument. So somewhere there must be a call to URL() with those values. Are you saying that none of the keys/values shown in that "query" argument to urllib.urlencode look like they are related to your app?
 

I mean, how do they arrive as keys to that function? I can't figure it out.

In the ticket details, when I click the "code" button related to my view, it shows an empty space:

Maybe try running a non-compiled version of the app and see if you get a code listing. Are there any calls to the URL() function anywhere in that view? Note, you should also look in any views that it extends or includes, as the compiled view includes the complete constructed view, with all extends and includes.

Anthony

[Lisandro]

Sorry for the delay on this, I wanted to make a second full review.

I confirm that there is no call to URL() in my code that uses vars argument with a 'title' key. I checked all the included and extended files.

However, I have these lines to point out, because they seem a bit "suspicious" to me, but I don't know, just in case you see something:

This is a login button, present in the layout, so it's in every page:

<a href="{{=URL('default', 'user', args='login', host=CONFIG.dominio_panel, vars={'_next': URL(args=request.args if 'l' in request.args else request.args + ['l'], vars=request.get_vars, host=True) or ''})}}">LOGIN</a>

The url of the login button uses the vars argument to pass the "_next" key. The _next key contains the current url (with current request.args and request.get_vars).

This is some javascript, to redirect to an url that, again, passes the _next key with the current url:

var full_url = location.protocol + "//" + window.location.hostname + location.pathname;
window.location = "{{=URL('contenido', 'editar', host=CONFIG.dominio_panel)}}" + "/" + contenido + "?_next=" + full_url;

About running non-compiled: the problem is that I have around 120 instances of this app running, and running them compiled is crucial for performance, I cannot run all of them non-compiled. 

However I will try to run a couple of instances non-compiled, to see if the error ticket says something else.

As usual, thanks a lot for the help!

I'll post again when I have news.

Regards,

Lisandro.

[Anthony]

This is a login button, present in the layout, so it's in every page:

<a href="{{=URL('default', 'user', args='login', host=CONFIG.dominio_panel, vars={'_next': URL(args=request.args if 'l' in request.args else request.args + ['l'], vars=request.get_vars, host=True) or ''})}}">LOGIN</a>

The url of the login button uses the vars argument to pass the "_next" key. The _next key contains the current url (with current request.args and request.get_vars).

Check out https://www.reddit.com/r/learnjavascript/comments/5jegfe/jquery_library_is_loading_extra_code_what_does_it/ -- the code shown in that case is using the exact same query string variables as you are seeing in your code. Could be a browser hijack that results in Ajax requests to your server. Your login button code takes the query string of the Ajax request (i.e., request.get_vars) and passes it as the "vars" argument to the URL() function. Because the query string includes some unicode characters, you get the error in question. If these are rogue Ajax requests not being generated by your app, presumably it doesn't matter that errors are being generated, but if you want to stop the errors, you could either transform request.get_vars before passing it to URL(), or do some validation of request.get_vars and only pass it to URL() when it represents a query string that is valid for your application.

Anthony

[Lisandro]

OMG! Anthony you really rock man!! 

Thanks **a lot**

That's exactly what's going on, and it explains the error being so sporadic.

Definitely, I'll transform the request.get_vars before passing it to URL() in order to avoid the error.

May I ask how did you figure out? I mean, did you already know about that jquery stuff, or did you made some search with the parameter's names? 

Anyway, good one, I really apreciate your help, as always!

P/D: I looked in the web2py's website and I didn't found any way to donate. I've seen an old post saying that it was better to donate to them who needed it most, the post gives a link to donate to another cause. But we (our company) would really like to contribute, not only to web2py, but also to you (that small group of people who is always here helping). 

[Anthony]

May I ask how did you figure out? I mean, did you already know about that jquery stuff, or did you made some search with the parameter's names?

Just did a Google search with some of the parameter names and found that Reddit post.
 

P/D: I looked in the web2py's website and I didn't found any way to donate. I've seen an old post saying that it was better to donate to them who needed it most, the post gives a link to donate to another cause. But we (our company) would really like to contribute, not only to web2py, but also to you (that small group of people who is always here helping).

Thanks for thinking of us. Maybe we should set something up.

Anthony