[OPEN-ILS-DEV] Syrup, OpenSRF 3.0, Evergreen 3.0.12 and JSONDecodeError

[Jason Stephenson]

Hi,

We upgraded to Evergreen 3.0.12 and the latest OpenSRF rel_3_0 last
night. Since doing the upgrade any time we try to view an item in
Syrup, we're getting a JSONDecodeError like the one below:

Environment:


Request Method: GET
Request URL: http://rb.cwmars.org/bcc/site/507/

Django Version: 1.4
Python Version: 2.6.6
Installed Applications:
['django.contrib.auth',
'django.contrib.contenttypes',
'django.contrib.messages',
'django.contrib.sessions',
'django.contrib.sites',
'django.contrib.admin',
'south',
'conifer.syrup']
Installed Middleware:
('django.middleware.common.CommonMiddleware',
'django.contrib.sessions.middleware.SessionMiddleware',
'django.contrib.auth.middleware.AuthenticationMiddleware',
'conifer.plumbing.genshi_support.GenshiMiddleware',
'django.middleware.locale.LocaleMiddleware',
'babeldjango.middleware.LocaleMiddleware',
'django.middleware.transaction.TransactionMiddleware',
'django.contrib.messages.middleware.MessageMiddleware')


Traceback:
File
"/usr/local/lib/python2.6/dist-packages/Django-1.4-py2.6.egg/django/core/handlers/base.py"
in get_response
111. response = callback(request,
*callback_args, **callback_kwargs)
File "/home/syrup/bcc/Syrup/conifer/syrup/views/_common.py" in hdlr
85. return handler(request, site_id, *args, **kwargs)
File "/home/syrup/bcc/Syrup/conifer/syrup/views/sites.py" in site_detail
229. return g.render('site_detail.xhtml', site=site)
File "/home/syrup/bcc/Syrup/conifer/plumbing/genshi_support.py" in render
77. return
HttpResponse(self.template(tname).generate(**kwargs).render('xhtml'))
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/core.py"
in render
184. return encode(generator, method=method,
encoding=encoding, out=out)
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/output.py"
in encode
57. return _encode(''.join(list(iterator)))
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/output.py"
in __call__
350. for kind, data, pos in stream:
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/output.py"
in __call__
669. for kind, data, pos in stream:
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/output.py"
in __call__
774. for kind, data, pos in chain(stream, [(None, None, None)]):
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/output.py"
in __call__
594. for ev in stream:
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/core.py"
in _ensure
289. for event in stream:
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/template/base.py"
in _include
618. for event in stream:
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/template/markup.py"
in _match
362. content = list(content)
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/template/base.py"
in _include
618. for event in stream:
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/template/markup.py"
in _strip
315. event = next()
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/template/base.py"
in _flatten
602. _exec_suite(data, ctxt, vars)
File
"/usr/local/lib/python2.6/dist-packages/Genshi-0.7-py2.6-linux-i686.egg/genshi/template/base.py"
in _exec_suite
306. suite.execute(ctxt)
File "/home/syrup/bcc/Syrup/conifer/templates/components/site.xhtml" in
<Suite u'downloads_allowed = site.allows_downloads_to(user) ...'>
38. downloads_allowed = site.allows_downloads_to(user)
File "/home/syrup/bcc/Syrup/conifer/plumbing/hooksystem.py" in callhook
24. return f(*args, **kwargs)
File "/home/syrup/bcc/Syrup/conifer/integration/evergreen_site.py" in
item_status
163. return self._item_status(item.bib_id)
File "/home/syrup/bcc/Syrup/conifer/plumbing/memoization.py" in func
35. v = self.cache[key] = f(*args,**kwargs),time.time()
File "/home/syrup/bcc/Syrup/conifer/integration/evergreen_site.py" in
_item_status
324. counts = E1(OPENSRF_COPY_COUNTS, bib_id,
EVERGREEN_STATUS_ORG, EVERGREEN_STATUS_DEPTH)
File "/home/syrup/bcc/Syrup/conifer/libsystems/evergreen/support.py" in
evergreen_request_single_result
69. resp = evergreen_request(method, *args, **kwargs)
File "/home/syrup/bcc/Syrup/conifer/libsystems/evergreen/support.py" in
evergreen_request
61. resp = json.load(req)
File "/usr/lib/pymodules/python2.6/simplejson/__init__.py" in load
328. use_decimal=use_decimal, **kw)
File "/usr/lib/pymodules/python2.6/simplejson/__init__.py" in loads
384. return _default_decoder.decode(s)
File "/usr/lib/pymodules/python2.6/simplejson/decoder.py" in decode
402. obj, end = self.raw_decode(s, idx=_w(s, 0).end())
File "/usr/lib/pymodules/python2.6/simplejson/decoder.py" in raw_decode
418. obj, end = self.scan_once(s, idx)

Exception Type: JSONDecodeError at /site/507/
Exception Value: Expecting , delimiter: line 1 column 2228 (char 2228)

I tried searching through Lp bugs, IRC Logs, Evergreen mailing list
archives, my local email, and Google. Nothing useful has so far turned
up. Most of the Google results that I have seen so far seem to be
issues with how the person asking the question has quoted their JSON.

I keep thinking that someone brought something like this up lately in
some Evergreen community forum, but I cannot find it. (I may be
imagining this. The mind is a tricky thing.) So, I am sending this to
the list in the hope that someone else has actually seen this before.

Looking at the trace above, it might have something to do with changes
in how copy counts are output, but I am not certain.

I will continue my own investigations.

Any help would be helpful.

Cheers,
Jason

[Jason Stephenson]

I have more information. When I try the back end call used by Syrup to
fetch copy counts with a record from the course that blows up, I get the
following:

srfsh# request open-ils.storage
open-ils.storage.biblio.record_entry.status_copy_location_count.atomic
[4211388, 160, 0]

Received Exception:
Name: osrfMethodException
Status: *** Call to
[open-ils.storage.biblio.record_entry.status_copy_location_count.atomic]
failed for session [1539000573.516499.153900057325003], thread trace [1]:
DBD::Pg::st execute failed: ERROR: invalid input syntax for integer:
"ARRAY(0xebc67e0)"
LINE 16: WHERE cn.record = 'ARRAY(0xebc67e0)'
^ [for Statement "
SELECT cp.circ_lib,
CASE WHEN cnp.id > -1 THEN cnp.label ELSE '' END,
cn.label,
CASE WHEN cns.id > -1 THEN cns.label ELSE '' END,
oils_i18n_xlate('asset.copy_location', 'acpl', 'name',
'id', cl.id::TEXT, ?),
cp.status,
count(cp.id)
FROM asset.copy cp,
asset.call_number cn,
asset.call_number_suffix cns,
asset.call_number_prefix cnp,
asset.copy_location cl,
config.copy_status cs,
actor.org_unit_descendants(?,?) d
WHERE cn.record = ?
AND cnp.id = cn.prefix
AND cns.id = cn.suffix
AND cp.call_number = cn.id
AND cp.location = cl.id
AND cp.circ_lib = d.id
AND cp.status = cs.id
AND cl.opac_visible IS TRUE
AND cp.opac_visible IS TRUE
AND cp.deleted IS FALSE
AND cl.deleted IS FALSE
AND cs.opac_visible IS TRUE
GROUP BY 1,2,3,4,5,6;
" with ParamValues: 1='en-US', 2='1', 3='0', 4='ARRAY(0xebc67e0)'] at
/usr/share/perl5/DBIx/ContextualFetch.pm line 52.


Status: 500
------------------------------------
Request Completed Successfully
Request Time in seconds: 0.215329
------------------------------------

So, a database error is definitely not JSON.

Looks like this one could be headed for Launchpad.

[Jason Stephenson]

Yeah, never mind. I see what I did wrong below.

Post by Jason Stephenson
I have more information. When I try the back end call used by Syrup to
fetch copy counts with a record from the course that blows up, I get the
srfsh# request open-ils.storage
open-ils.storage.biblio.record_entry.status_copy_location_count.atomic
[4211388, 160, 0]
Name: osrfMethodException
Status: *** Call to
[open-ils.storage.biblio.record_entry.status_copy_location_count.atomic]
"ARRAY(0xebc67e0)"
LINE 16: WHERE cn.record = 'ARRAY(0xebc67e0)'
^ [for Statement "
SELECT cp.circ_lib,
CASE WHEN cnp.id > -1 THEN cnp.label ELSE '' END,
cn.label,
CASE WHEN cns.id > -1 THEN cns.label ELSE '' END,
oils_i18n_xlate('asset.copy_location', 'acpl', 'name',
'id', cl.id::TEXT, ?),
cp.status,
count(cp.id)
FROM asset.copy cp,
asset.call_number cn,
asset.call_number_suffix cns,
asset.call_number_prefix cnp,
asset.copy_location cl,
config.copy_status cs,
actor.org_unit_descendants(?,?) d
WHERE cn.record = ?
AND cnp.id = cn.prefix
AND cns.id = cn.suffix
AND cp.call_number = cn.id
AND cp.location = cl.id
AND cp.circ_lib = d.id
AND cp.status = cs.id
AND cl.opac_visible IS TRUE
AND cp.opac_visible IS TRUE
AND cp.deleted IS FALSE
AND cl.deleted IS FALSE
AND cs.opac_visible IS TRUE
GROUP BY 1,2,3,4,5,6;
" with ParamValues: 1='en-US', 2='1', 3='0', 4='ARRAY(0xebc67e0)'] at
/usr/share/perl5/DBIx/ContextualFetch.pm line 52.
Status: 500
------------------------------------
Request Completed Successfully
Request Time in seconds: 0.215329
------------------------------------
So, a database error is definitely not JSON.
Looks like this one could be headed for Launchpad.

[Jason Stephenson]

OK. I am stumped.

After fixing my request to:

request open-ils.search
open-ils.search.biblio.copy_counts.location.summary.retrieve 4211388, 160, 0

I see no difference in the output between a system with a copy of
production data still running on our pre-upgrade version of Evergreen
and the post-upgrade version of Evergreen

Post-upgrade:

Received Data: [
[
"160",
"",
"AHS 111 Life Sprt",
"",
"Reserve",
{
"0":1
}
]
]


Pre-upgrade:

Received Data: [
[
"160",
"",
"AHS 111 Life Sprt",
"",
"Reserve",
{
"0":1
}
]
]

I cannot update packages on the Syrup server because it is running an
end-of-life release of Debian. (I have not been able to get Syrup
running on a more recent distro, and I have tried.)

So, guess I'm stuck unless someone else notices something that I don't.

Jason

[Jason Stephenson]

OK. You are all probably sick of these emails by now, but lucky for you
this is the last one.

I fixed the problem. Apparently, our Syrup server expects to have
OpenSRF services running locally that can talk to the production db
server. However, them not running was not exactly my problem.

I first tried stopping the service and got different errors, so I
restarted them and the earlier reported error came back.

I tried my srfsh call from the Syrup server for a change, and got a
message that the private router was not connected to the network.
However, osrf_control --diagnostic said that it most certainly was running.

So, I look at /etc/hossts and find conflicting IP address for the
private domain. I removed one set of public and private IPs for the
router and that resolved it.

Strange, but true.