[Koha] Help debugging Internal Server Error

Fri Feb 19 08:47:26 NZDT 2021

Hey Jonathan,

Thanks for responding.  I did check the wiki to make sure buster was supported before upgrading to that release.

When I did tail -f on the other logs I saw a lot of stuff going by on the screen and updating in real time, so I decided to just do tail on all the non-zero sized logs.  Results pasted below.  Nothing jumps out at me so I'm not sure what to try next.  Maybe something will jump out for you or someone else.

Thanks - Doug

r# tail opac-error.log
[Thu Feb 18 09:10:52.259211 2021] [proxy:warn] [pid 10369] [client 174.138.4.57:39958] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:10:52.563974 2021] [proxy:warn] [pid 10371] [client 174.138.4.57:40078] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:10:52.860067 2021] [proxy:warn] [pid 10372] [client 174.138.4.57:40190] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:10:53.168740 2021] [proxy:warn] [pid 10373] [client 174.138.4.57:40310] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:10:53.483919 2021] [proxy:warn] [pid 10375] [client 174.138.4.57:40398] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:10:53.778907 2021] [proxy:warn] [pid 10377] [client 174.138.4.57:40484] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:11:01.596676 2021] [proxy:warn] [pid 10386] [client 174.138.4.57:41230] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:39:48.029477 2021] [proxy:warn] [pid 12473] [client 172.104.242.173:52489] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
[Thu Feb 18 09:39:58.559208 2021] [proxy_http:error] [pid 12473] (70007)The timeout specified has expired: [client 172.104.242.173:52489] AH01095: prefetch request body failed to 0.0.0.0:0 (httpd-UDS) from 172.104.242.173 ()
[Thu Feb 18 12:11:54.869784 2021] [proxy:warn] [pid 23443] [client 205.185.122.102:38244] AH01092: no HTTP 0.9 request (with no host line) on incoming request and preserve host set forcing hostname to be library.sarsf.org for uri /cgi-bin/koha/errors/400.pl
#

# tail plack-error.log
[Thu Feb 18 12:20:08 2021] starman: Subroutine CORE::GLOBAL::time redefined at /usr/share/perl5/Test/MockTime.pm line 20, <DATA> line 755.
[Thu Feb 18 12:20:08 2021] starman: Prototype mismatch: sub CORE::GLOBAL::time () vs none at /usr/share/perl5/Test/MockTime.pm line 20, <DATA> line 755.
[Thu Feb 18 12:20:08 2021] starman: Subroutine CORE::GLOBAL::localtime redefined at /usr/share/perl5/Test/MockTime.pm line 21, <DATA> line 755.
[Thu Feb 18 12:20:08 2021] starman: Prototype mismatch: sub CORE::GLOBAL::localtime (;$) vs none at /usr/share/perl5/Test/MockTime.pm line 21, <DATA> line 755.
[Thu Feb 18 12:20:08 2021] starman: Subroutine CORE::GLOBAL::gmtime redefined at /usr/share/perl5/Test/MockTime.pm line 22, <DATA> line 755.
[Thu Feb 18 12:20:08 2021] starman: Prototype mismatch: sub CORE::GLOBAL::gmtime (;$) vs none at /usr/share/perl5/Test/MockTime.pm line 22, <DATA> line 755.
DBIx::Class::Storage::DBI::_dbh_execute(): Unknown column 'me.exclude_from_local_holds_priority' in 'field list' at /usr/share/koha/lib/Koha/Objects.pm line 96
DBIx::Class::Storage::DBI::_dbh_execute(): Unknown column 'items.exclude_from_local_holds_priority' in 'field list' at /usr/share/koha/lib/Koha/Objects.pm line 332
DBIx::Class::Storage::DBI::_dbh_execute(): Unknown column 'items.exclude_from_local_holds_priority' in 'field list' at /usr/share/koha/lib/Koha/Objects.pm line 96
DBIx::Class::Storage::DBI::_dbh_execute(): Unknown column 'me.exclude_from_local_holds_priority' in 'field list' at /usr/share/koha/lib/Koha/Objects.pm line 96
#

# tail plack-intranet-error.log
[2021/02/17 15:37:56] [WARN] Locale::Codes will be removed from the Perl core distribution in the next major release. Please install the separate liblocale-codes-perl package. It is being used at /usr/share/perl/5.28/Locale/Language.pm, line 22.
[2021/02/17 16:54:11] [WARN] Subroutine CORE::GLOBAL::time redefined at /usr/share/perl5/Test/MockTime.pm line 20, <DATA> line 755.
[2021/02/17 16:54:11] [WARN] Prototype mismatch: sub CORE::GLOBAL::time () vs none at /usr/share/perl5/Test/MockTime.pm line 20, <DATA> line 755.
[2021/02/17 16:54:11] [WARN] Subroutine CORE::GLOBAL::localtime redefined at /usr/share/perl5/Test/MockTime.pm line 21, <DATA> line 755.
[2021/02/17 16:54:11] [WARN] Prototype mismatch: sub CORE::GLOBAL::localtime (;$) vs none at /usr/share/perl5/Test/MockTime.pm line 21, <DATA> line 755.
[2021/02/17 16:54:11] [WARN] Subroutine CORE::GLOBAL::gmtime redefined at /usr/share/perl5/Test/MockTime.pm line 22, <DATA> line 755.
[2021/02/17 16:54:11] [WARN] Prototype mismatch: sub CORE::GLOBAL::gmtime (;$) vs none at /usr/share/perl5/Test/MockTime.pm line 22, <DATA> line 755.
[2021/02/17 16:54:12] [WARN] Locale::Codes will be removed from the Perl core distribution in the next major release. Please install the separate liblocale-codes-perl package. It is being used at /usr/share/perl/5.28/Locale/Language.pm, line 22.
[2021/02/18 11:44:19] [WARN] DBIx::Class::Storage::DBI::select_single(): Query returned more than one row.  SQL that returns multiple rows is DEPRECATED for ->find and ->single at /usr/share/koha/lib/Koha/Objects.pm line 96
[2021/02/18 12:19:49] [WARN] DBIx::Class::Storage::DBI::select_single(): Query returned more than one row.  SQL that returns multiple rows is DEPRECATED for ->find and ->single at /usr/share/koha/lib/Koha/Objects.pm line 96
#

# tail plack.log
185.191.171.19 - - [18/Feb/2021:12:27:30 -0700] "GET /opac/opac-search.pl?format=rss&q=ccl%3D%28su%3A%7BIndians%20of%20North%20America%7D%29%20AND%20%28su%3A%7BPolitics%20and%20government.%7D%29%20and%20su-to%3ASelf-determination%2C%20National%20and%20su-to%3ASelf-determination%2C%20National%20and%20au%3AWilson%2C%20Angela%20Cavender.%20and%20location%3ASAR%20Publications%20and%20au%3AWilson%2C%20Angela%20Cavender. HTTP/1.1" 200 2063 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.8 - - [18/Feb/2021:12:27:32 -0700] "GET /opac/opac-search.pl?format=rss&q=ccl%3D%28su%3A%7BUnited%20States%7D%29%20AND%20%28su%3A%7BPolitics%20and%20government.%7D%29%20and%20su-to%3ADecolonization%20and%20su-geo%3AUnited%20States%20and%20su-to%3AIndians%20of%20North%20America%20and%20su-to%3ASelf-determination%2C%20National%20and%20au%3AWilson%2C%20Angela%20Cavender.%20and%20su-to%3ADecolonization%20and%20su-to%3AIndians%20of%20North%20America%20and%20su-to%3APostcolonialism%20and%20su-to%3AIndians%20of%20North%20America HTTP/1.1" 200 2495 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.24 - - [18/Feb/2021:12:27:34 -0700] "GET /opac/opac-search.pl?format=rss&q=ccl%3D%28su%3A%7BUnited%20States%7D%29%20AND%20%28su%3A%7BRace%20relations.%7D%29%20and%20itype%3ABK%20and%20su-to%3AIndians%20of%20North%20America%20and%20se%3AFirst%20peoples%20%3A%20new%20directions%20in%20indigenous%20studies%20and%20location%3AGEN%20and%20itype%3ABK%20and%20su-to%3AIndians%20of%20North%20America%20and%20itype%3ABK%20and%20itype%3ABK HTTP/1.1" 200 2127 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
114.119.156.152 - - [18/Feb/2021:12:27:39 -0700] "GET /opac/opac-search.pl?q=ccl%3D%28su%3A%7BPueblo%20Indians.%20%7D%29%20and%20itype%3ABK%20and%20su-to%3APueblo%20Indians.%20and%20su-geo%3ANew%20Mexico%20and%20itype%3ABK%20and%20su-to%3APueblo%20Indians%20and%20su-to%3APueblo%20Indians.%20and%20se%3AReports%20of%20the%20Chaco%20Center%20%3B%20and%20su-to%3APueblo%20Indians%20and%20se%3AReports%20of%20the%20Chaco%20Center%20and%20itype%3ABK&sort_by=pubdate_asc&limit=au%3ABerger%2C%20S. HTTP/1.1" 200 37057 "-" "Mozilla/5.0 (Linux; Android 7.0;) AppleWebKit/537.36 (KHTML, like Gecko) Mobile Safari/537.36 (compatible; PetalBot;+https://aspiegel.com/petalbot)"
185.191.171.5 - - [18/Feb/2021:12:27:52 -0700] "GET /opac/opac-search.pl?format=rss&q=ccl%3D%28su%3A%7BSocial%20archaeology.%7D%29%20and%20su-to%3AArchaeology%20and%20location%3AGEN%20and%20location%3AGEN%20and%20se%3ACambridge%20world%20archaeology%20and%20se%3ACambridge%20world%20archaeology%20and%20itype%3ABK%20and%20su-to%3AExcavations%20%20Archaeology%20%20and%20su-to%3ASocial%20archaeology HTTP/1.1" 200 2007 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.44 - - [18/Feb/2021:12:28:05 -0700] "GET /opac/opac-search.pl?limit=su-to%3AArchaeology.&q=ccl%3D%28su%3A%7BArchaeologists%7D%29%20AND%20%28su%3A%7BBiography.%7D%29%20and%20itype%3ABK%20and%20su-to%3AArchaeologists%20and%20su-to%3AArchaeology%20and%20su-to%3ABiography&sort_by=title_az HTTP/1.1" 200 35482 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.11 - - [18/Feb/2021:12:28:08 -0700] "GET /opac/opac-search.pl?limit=itype%3ABK&q=ccl%3D%28su%3A%7BIndians%20of%20North%20America%7D%29%20AND%20%28su%3A%7BPolitics%20and%20government.%7D%29%20and%20su-to%3ASelf-determination%2C%20National%20and%20su-to%3AIndians%20of%20North%20America%20and%20su-geo%3AUnited%20States%20and%20itype%3ABK%20and%20su-geo%3AUnited%20States%20and%20%28%20%28%20allrecords%2CAlwaysMatches%3A%27%27%20not%20onloan%2CAlwaysMatches%3A%27%27%29%20and%20%28lost%2Cst-numeric%3D0%29%20%29%20and%20itype%3ABK&sort_by=title_az HTTP/1.1" 200 37626 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.8 - - [18/Feb/2021:12:28:10 -0700] "GET /opac/opac-search.pl?limit=su-to%3ASelf-determination%2C%20National&q=ccl%3D%28su%3A%7BUnited%20States%7D%29%20AND%20%28su%3A%7BPolitics%20and%20government.%7D%29%20and%20su-to%3ASelf-determination%2C%20National%20and%20itype%3ABK%20and%20au%3AWilson%2C%20Angela%20Cavender.%20and%20su-to%3ACultural%20property%20and%20su-to%3ACultural%20property%20and%20su-to%3AIndians%20of%20North%20America&sort_by=title_az HTTP/1.1" 200 36774 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.42 - - [18/Feb/2021:12:28:34 -0700] "GET /opac/opac-search.pl?limit=au%3AWhite%2C%20Leslie%20A.%2C&q=ccl%3D%28su%3A%7BIndian%20Arts%20Fund%20Santa%20Fe%2C%20N.M.%7D%29%20and%20itype%3AAM%20and%20itype%3AAM%20and%20au%3AAlbright%2C%20Horace.%20and%20su-to%3APottery%20and%20su-to%3APottery%20and%20au%3ALa%20Farge%2C%20Oliver&sort_by=title_az HTTP/1.1" 200 35856 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
185.191.171.7 - - [18/Feb/2021:12:28:48 -0700] "GET /opac/opac-search.pl?limit=au%3ASabloff%2C%20Jeremy%20A.&q=ccl%3DProvider%3AUniversity%20of%20New%20Mexico%20Press%2C%20and%20su-geo%3ACentral%20America%20and%20se%3ASchool%20of%20American%20Research%20advanced%20seminar%20series%20and%20se%3AAdvanced%20seminar%20series%20and%20su-to%3AIndians%20of%20Mexico%20and%20location%3ASAR%20Publications%20and%20se%3AAdvanced%20seminar%20series%20and%20su-geo%3ACentral%20America%20and%20se%3AAdvanced%20seminar%20series%20and%20su-to%3AIndians%20of%20Mexico%20and%20se%3AAdvanced%20seminar%20series%20and%20su-to%3AMayas%20and%20%28%20%28allrecords%2CAlwaysMatches%3D%27%27%29%20and%20%28not-onloan-count%2Cst-numeric%20%3E%3D%201%29%20and%20%28lost%2Cst-numeric%3D0%29%20%29&sort_by=title_az HTTP/1.1" 200 38781 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)"
#

# tail plack-opac-error.log
[2021/02/18 12:29:22] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:29:31] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:29:37] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:29:48] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:29:48] [WARN] DBD::mysql::st execute failed: Unknown column 'me.exclude_from_local_holds_priority' in 'field list' [for Statement "SELECT `me`.`itemnumber`, `me`.`biblionumber`, `me`.`biblioitemnumber`, `me`.`barcode`, `me`.`dateaccessioned`, `me`.`booksellerid`, `me`.`homebranch`, `me`.`price`, `me`.`replacementprice`, `me`.`replacementpricedate`, `me`.`datelastborrowed`, `me`.`datelastseen`, `me`.`stack`, `me`.`notforloan`, `me`.`damaged`, `me`.`damaged_on`, `me`.`itemlost`, `me`.`itemlost_on`, `me`.`withdrawn`, `me`.`withdrawn_on`, `me`.`itemcallnumber`, `me`.`coded_location_qualifier`, `me`.`issues`, `me`.`renewals`, `me`.`reserves`, `me`.`restricted`, `me`.`itemnotes`, `me`.`itemnotes_nonpublic`, `me`.`holdingbranch`, `me`.`timestamp`, `me`.`location`, `me`.`permanent_location`, `me`.`onloan`, `me`.`cn_source`, `me`.`cn_sort`, `me`.`ccode`, `me`.`materials`, `me`.`uri`, `me`.`itype`, `me`.`more_subfields_xml`, `me`.`enumchron`, `me`.`copynumber`, `me`.`stocknumber`, `me`.`new_status`, `me`.`exclude_from_local_holds_priority` FROM `items` `me` WHERE ( `me`.`itemnumber` = ? )" with ParamValues: 0=3278] at /usr/share/perl5/DBIx/Class/Storage/DBI.pm line 1836.
[2021/02/18 12:29:58] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:30:09] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:30:11] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:30:13] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
[2021/02/18 12:30:16] [WARN] Use of uninitialized value $times in subtraction (-) at /usr/share/koha/lib/C4/Search.pm line 1759.
#

# tail zebra-output.log
13:14:46-17/02 zebrasrv(425529) [warn] ir_session (exception)
13:15:10-17/02 zebrasrv(425530) [warn] ir_session (exception)
13:15:19-17/02 zebrasrv(425531) [warn] ir_session (exception)
13:15:22-17/02 zebrasrv(425532) [warn] ir_session (exception)
13:15:25-17/02 zebrasrv(425533) [warn] ir_session (exception)
13:15:30-17/02 zebrasrv(425534) [warn] ir_session (exception)
13:15:31-17/02 zebrasrv(425535) [warn] ir_session (exception)
13:15:35-17/02 zebrasrv(425536) [warn] ir_session (exception)
13:15:36-17/02 zebrasrv(425537) [warn] ir_session (exception)
13:15:39-17/02 zebrasrv(425538) [warn] ir_session (exception)
#

-----Original Message-----
From: Jonathan Druart [mailto:jonathan.druart at bugs.koha-community.org] 
Sent: Thursday, February 18, 2021 7:57 AM
To: Doug Dearden <dearden at sarsf.org>
Cc: koha at lists.katipo.co.nz
Subject: Re: [Koha] Help debugging Internal Server Error

Hey, Buster is Debian 10, not 11!
So we are supporting it and it's known to work correctly!

Le jeu. 18 févr. 2021 à 10:11, Jonathan Druart
<jonathan.druart at bugs.koha-community.org> a écrit :
>
> Hello Doug,
>
> What do you see in the other error log files? (tail -f
> /var/log/koha/<instance>/*.log)
>
> Our support for "buster" is buggy at the moment.
> Have a look at bug 26893 (New version of JSON::Validator (D11) breaks
> our REST API routes)
> https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=26893
>
> Regards,
> Jonathan
>
> Le jeu. 18 févr. 2021 à 01:18, Doug Dearden <dearden at sarsf.org> a écrit :
> >
> > Hey Everyone,
> >
> > I did an upgrade today on our server.  We were running version 19.05 on stretch, and we needed to upgrade to buster and I decided to get up to the latest stable Koha release at the same time.  The upgrade seemed to go OK but now when I go to our OPAC and do a search I get no results, and if I click on a link for recently added items I get an internal server error.  There are some Perl Modules showing as not installed -  Locale::XGettext::TT2 , Text::CSV::Unicode , Selenium::Remote::Driver , Test::DBIx::Class, HTTPD::Bench::ApacheBench .  There was a warning on the System Information tab about the <lockdir> not being defined in koha-conf.xml so I added that to the config section in there and that warning is now gone.  I thought this might be related to plack.  If I enter
> > koha-plack -stop <instance>
> > it returns
> > Stopping Plack daemon for <instance>
> > When I enter koha-plack -disable <instance>
> > it returns
> > Plack not disabled for <instance> OPAC
> > Plack not disabled for <instance> Intranet
> > With Plack stopped the error changes to Service Unavailable
> >
> > I tried commenting out the Include /etc/koha/apache-shared-opac-plack.conf line from the apache config and restarting apache, but still got Service Unavailable .
> >
> > /var/log/koha/<instance>/opac-error.log shows this repeatedly
> > [Wed Feb 17 17:03:58.912977 2021] [proxy_http:error] [pid 4810] [client 185.191.171.3:37140] AH01114: HTTP: failed to make connection to backend: httpd-UDS
> >
> > I'm not really sure what logs I should be looking at to troubleshoot this.
> >
> > Thanks,
> >
> > Doug Dearden
> > Director / Information Technology
> > School for Advanced Research (SAR)
> > PO Box 2188 / Santa Fe / NM / 87504-2188
> > 505-954-7220 (work) / 505-690-1535 (cell)
> > www.sarweb.org<http://www.sarweb.org/>
> >
> > EXPLORING HUMANITY. UNDERSTANDING OUR WORLD.
> >
> > Receive the SAR monthly E-News: SIGN UP HERE <https://sarweb.org/about/e-news-signup/>
> >
> > _______________________________________________
> >
> > Koha mailing list  http://koha-community.org
> > Koha at lists.katipo.co.nz
> > Unsubscribe: https://lists.katipo.co.nz/mailman/listinfo/koha