MythTV-Clients / MythTV-Android-Frontend

Implementation of MythTV .25+ Services API for Android
GNU General Public License v3.0
66 stars 16 forks source link

No recordings displayed on recordings screen #219

Closed Speckto closed 10 years ago

Speckto commented 10 years ago

Hi,

I am using version 1.10.1 of the android app. I run mythtv 0.26.0.

When I access the recordings screen, no recordings are displayed. The program guide does download ok, so it appears to have connectivity to the backend.

The application starts and appears to sync the program guide. I tap the recordings icon and I see a message "Recordings are up to date!" but no recordings are displayed.

I enabled logging on mythbackend (the upnp stuff from the wiki) and connected "monitor" up to my android device then captured the logging from when I clicked the 'recordings' icon:

Backend log shows that the connection is being made and urls are being requested:

2013-10-09 20:42:44.969357 I [2595/8227] HttpServer99 httprequest.cpp:242 (SendResponse) - HTTPRequest::SendResponse(xml/html) () :200 OK -> 192.168.0.101: 4
2013-10-09 20:43:10.651315 I [2595/8227] HttpServer99 httprequest.cpp:1338 (ExtractMethodFromURL) - ExtractMethodFromURL(end) : GetHostName : /Myth
2013-10-09 20:43:10.651334 I [2595/8227] HttpServer99 servicehost.cpp:281 (ProcessRequest) - ServiceHost::ProcessRequest: GetHostName : GET /Myth/GetHostName HTTP/1.1
2013-10-09 20:43:10.651440 I [2595/8227] HttpServer99 httprequest.cpp:242 (SendResponse) - HTTPRequest::SendResponse(xml/html) () :200 OK -> 192.168.0.101: 4
2013-10-09 20:43:11.376463 I [2595/8227] HttpServer99 httprequest.cpp:1338 (ExtractMethodFromURL) - ExtractMethodFromURL(end) : GetRecordedList : /Dvr
2013-10-09 20:43:11.376481 I [2595/8227] HttpServer99 servicehost.cpp:281 (ProcessRequest) - ServiceHost::ProcessRequest: GetRecordedList : GET /Dvr/GetRecordedList HTTP/1.1
2013-10-09 20:43:11.947946 I [2595/8227] HttpServer99 httprequest.cpp:242 (SendResponse) - HTTPRequest::SendResponse(xml/html) () :200 OK -> 192.168.0.101: 4

I had a look at the log on the android device, and after clicking the recordings button, I see an exception being thrown which looks like it may be related:

10-09 20:43:10.646: V/MainApplication(17472): getMythServicesApi : exit
10-09 20:43:10.766: D/dalvikvm(17472): GC_CONCURRENT freed 197K, 3% free 10584K/10820K, paused 3ms+7ms, total 32ms
10-09 20:43:10.901: D/dalvikvm(17472): GC_CONCURRENT freed 498K, 5% free 10632K/11168K, paused 2ms+3ms, total 31ms
10-09 20:43:11.016: D/dalvikvm(17472): GC_CONCURRENT freed 495K, 5% free 10703K/11236K, paused 2ms+2ms, total 32ms
10-09 20:43:11.121: D/dalvikvm(17472): GC_CONCURRENT freed 565K, 6% free 10742K/11344K, paused 3ms+2ms, total 35ms
10-09 20:43:11.121: D/dalvikvm(17472): WAIT_FOR_CONCURRENT_GC blocked 3ms
10-09 20:43:11.196: D/dalvikvm(17472): GC_CONCURRENT freed 599K, 6% free 10744K/11380K, paused 1ms+1ms, total 27ms
10-09 20:43:12.466: D/i(17238): scheduled task [GmmLocationControllerStatus Update]
10-09 20:43:12.471: D/dalvikvm(17472): GC_CONCURRENT freed 436K, 5% free 10824K/11380K, paused 2ms+1ms, total 26ms
10-09 20:43:12.546: E/RecordedDownloadService(17472): onHandleIntent : error
10-09 20:43:12.546: E/RecordedDownloadService(17472): org.mythtv.services.api.MythServiceApiRuntimeException: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]; nested exception is org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.mythtv.services.api.dvr.impl.DvrTemplate.getRecordedList(DvrTemplate.java:356)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.mythtv.service.dvr.RecordedDownloadService.download(RecordedDownloadService.java:160)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.mythtv.service.dvr.RecordedDownloadService.onHandleIntent(RecordedDownloadService.java:127)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:65)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at android.os.Handler.dispatchMessage(Handler.java:99)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at android.os.Looper.loop(Looper.java:137)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at android.os.HandlerThread.run(HandlerThread.java:61)
10-09 20:43:12.546: E/RecordedDownloadService(17472): Caused by: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.http.converter.json.MappingJackson2HttpMessageConverter.readInternal(MappingJackson2HttpMessageConverter.java:126)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.http.converter.AbstractHttpMessageConverter.read(AbstractHttpMessageConverter.java:147)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.web.client.HttpMessageConverterExtractor.extractData(HttpMessageConverterExtractor.java:76)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.web.client.RestTemplate$ResponseEntityResponseExtractor.extractData(RestTemplate.java:655)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.web.client.RestTemplate$ResponseEntityResponseExtractor.extractData(RestTemplate.java:641)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:484)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:453)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:429)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at org.mythtv.services.api.dvr.impl.DvrTemplate.getRecordedList(DvrTemplate.java:351)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   ... 6 more
10-09 20:43:12.546: E/RecordedDownloadService(17472): Caused by: com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-09 20:43:12.546: E/RecordedDownloadService(17472):  at [Source: java.util.zip.GZIPInputStream@41fc0528; line: 1, column: 94105]
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1378)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:599)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._reportInvalidOther(UTF8StreamJsonParser.java:3014)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._reportInvalidOther(UTF8StreamJsonParser.java:3021)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._decodeUtf8_3fast(UTF8StreamJsonParser.java:2843)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString2(UTF8StreamJsonParser.java:2143)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString(UTF8StreamJsonParser.java:2092)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.getValueAsString(UTF8StreamJsonParser.java:291)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:24)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:11)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:375)
10-09 20:43:12.546: E/RecordedDownloadService(17472):   at com.fasterxml.jackson.databind.deser.impl.MethodProperty.deserializeAn
10-09 20:43:12.551: I/RecordingsFragment(17406): RecordedDownloadReceiver.onReceive : enter
10-09 20:43:12.551: I/RecordingsFragment(17406): RecordedDownloadReceiver.onReceive : complete=Recorded Programs Download Service Finished
10-09 20:43:12.551: D/RecordedDownloadService(17472): onHandleIntent : exit
10-09 20:43:12.556: I/RecordingsFragment(17406): RecordedDownloadReceiver.onReceive : exit

I used wget to access the Dvr/GetRecordedList xml, and iconv seems to be able to convert the retrieved file from UTF-8 without any issues.

There is in fact a repeating error whilst downloading the program guide data as well - not sure if it is related:

10-09 20:42:43.676: V/MainApplication(17453): getMythServicesApi : enter
10-09 20:42:43.676: V/MainApplication(17453): getMasterBackend : enter
10-09 20:42:43.676: V/MainApplication(17453): getMasterBackend : exit
10-09 20:42:43.676: D/LocationProfileDaoHelper(17453): findConnectedProfile : enter
10-09 20:42:43.681: V/LocationProfileDaoHelper(17453): convertCursorToLocationProfile : enter
10-09 20:42:43.681: V/LocationProfileDaoHelper(17453): convertCursorToLocationProfile : exit
10-09 20:42:43.686: D/LocationProfileDaoHelper(17453): findConnectedProfile : exit
10-09 20:42:43.686: V/MainApplication(17453): getMythServicesApi : exit
10-09 20:42:43.721: D/dalvikvm(17453): GC_CONCURRENT freed 764K, 8% free 10705K/11576K, paused 1ms+3ms, total 28ms
10-09 20:42:43.786: D/dalvikvm(17453): GC_CONCURRENT freed 477K, 7% free 10832K/11576K, paused 3ms+2ms, total 28ms
10-09 20:42:43.786: D/dalvikvm(17453): WAIT_FOR_CONCURRENT_GC blocked 7ms
10-09 20:42:43.841: D/dalvikvm(17453): GC_CONCURRENT freed 683K, 7% free 10796K/11576K, paused 1ms+1ms, total 19ms
10-09 20:42:43.841: D/dalvikvm(17453): WAIT_FOR_CONCURRENT_GC blocked 7ms
10-09 20:42:43.891: D/dalvikvm(17453): GC_CONCURRENT freed 611K, 7% free 10820K/11576K, paused 2ms+1ms, total 20ms
10-09 20:42:43.891: D/dalvikvm(17453): WAIT_FOR_CONCURRENT_GC blocked 7ms
10-09 20:42:43.941: D/dalvikvm(17453): GC_CONCURRENT freed 640K, 7% free 10822K/11576K, paused 2ms+1ms, total 25ms
10-09 20:42:43.941: D/dalvikvm(17453): WAIT_FOR_CONCURRENT_GC blocked 7ms
10-09 20:42:44.256: E/ProgramGuideDownloadService(17453): download : error downloading program guide
10-09 20:42:44.256: V/ProgramGuideDownloadService(17453): download : exit

The program guide appears to function correctly - but I haven't looked at it in detail.

Any idea how I can get my recordings screen working?

Thanks

billmeek commented 10 years ago

Wow, great data gathering! And yes, the exception looks related, especially the line: DvrTemplate.getRecordedList(DvrTemplate.java:356).

Would you try this please (if you already haven't:)

wget -d \
   --header='Accept: application/json' \
   --header='Accept-Encoding: gzip' \
   --output-document=/tmp/JsonData.gz \
   <yourBackendHostname>:6544/Dvr/GetRecordedList?Descending=true

You should then be able to gunzip /tmp/JsonData.gz.

The above will be very long single line that starts similar to this:

{"ProgramList": {"StartIndex": "0", "Count": "246", "TotalAvailable": "246", "AsOf":...

Just to save time, please mention if you build MythTV from source.

Let's start with that and see what happens, thanks.

billmeek commented 10 years ago

@Speckto, note that 1.20.0 was released for beta testers today, 10/10/2013. If you join: https://plus.google.com/u/0/communities/104432707624078706786 you can get the release.

Speckto commented 10 years ago

Hi,

Thanks for the quick response.

I logged in using the link from the beta testers site and it redirected me to https://play.google.com/apps/testing/org.mythtv which was an error page stating the requested URL was not found. Potentially this is because I am not a member of google+ - I'm not really sure why that doesn't work. I'll fiddle with it later and see if I can get it working.

I am running Gentoo so yes I have compiled from source via emerge. My mythtv details are:

> mythbackend --version
Please attach all output as a file in bug reports.
MythTV Version : v0.26.0
MythTV Branch : fixes/0.26
Network Protocol : 75
Library API : 0.26.20130225-1
QT Version : 4.8.4
Options compiled in:
 linux profile use_hidesyms using_alsa using_oss using_backend using_bindings_perl using_bindings_python using_bindings_php using_dvb using_firewire using_frontend using_hdhomerun using_ceton using_hdpvr using_iptv using_ivtv using_libcrypto using_libxml2 using_libudf using_lirc using_mheg using_opengl_video using_qtwebkit using_qtscript using_qtdbus using_v4l2 using_x11 using_xrandr using_xv using_bindings_perl using_bindings_python using_bindings_php using_mythtranscode using_opengl using_vdpau using_ffmpeg_threads using_live using_mheg using_libass using_libxml2 using_libudf

> equery list mythtv
 * Searching for mythtv ...
[IP-] [  ] media-tv/mythtv-0.26.0_p20130526:0

I ran the wget command - I had to remove the -d as wget was not compiled with debug support but the command worked anyway and I ended up with a 45K gzip.

I uncompressed it without issue and ran iconv to validate it (I'm unsure how useful this is):

> iconv -f UTF-8 JsonData -o /dev/null
iconv: illegal input sequence at position 53935

Opening that in Gvim it gives a description for an episode in the series New Girl:

while Nick and Winston spend some 'guy time' with her fiance Shivrang.

The 'e' on fiance in the above is actually accented (lost in my copy-paste). Gvim's goto takes me to the letter 'c' in fiance. Console vim won't display the accented e (or any other accented characters in other recordings) but gvim does. I checked the episode using mythfrontend and it displays the correctly accented character as well.

I've uploaded the gzip here - not sure if you needed it as you didn't say: http://random.divergentlocus.co.uk/filedump/JsonData.gz

Now I can probably just delete the episode to fix this (assuming that is the only error which I somehow doubt; either way I'd prefer not to), but I'm guessing you might want some more diagnostics before I do anything like that given this displays in the front-end ok?

Cheers.

billmeek commented 10 years ago

@Speckto, it would be great if you kept the episode(s) causing the error in MythTV Android Frontend (assuming that's indeed the cause.)

I'll take a look at the .gz you posted.

billmeek commented 10 years ago

@Speckto, OK, here's a hex dump of the 1st instance:

66 69 61 6e 63 e9 20 53  68 69 76 72 61 6e 67 2e  |fianc. Shivrang.|

And, from Wikipedia, 0xe9 would fit:

16  U+0800  U+FFFF  3   1110xxxx    10xxxxxx    10xxxxxx

Which says that e9 should have three bytes where yours has only one and the 2nd, in fact, is the x020 (a space shows up as a . in hd) the error is complaining about.

So, where's it coming from? [answer, I don't know] Can you get into mysql on your backend and type: \s The response should contain lines like this:

Server characterset:    latin1
Db     characterset:    utf8
Client characterset:    utf8
Conn.  characterset:    utf8

Here's an hd from my program table where the word que[space] is followed by the two byte sequence c3 a9 for é then the letter l:

69 6a 6f 73 20 6c 6f 20  71 75 65 20 c3 a9 6c 20  |ijos lo que ..l |

@dmfrey, I found a comment while googling, could MAF be modified to "use JDK's InputStreamReader with proper encoding to decode it, and construct parser/mapper from Reader". Or, is JSON even used in 1.20.x?

Speckto commented 10 years ago

The output of '\s' is:

mysql  Ver 14.14 Distrib 5.1.70, for pc-linux-gnu (i686) using readline 5.1

Connection id:          54
Current database:       mythconverg
Current user:           root@localhost
SSL:                    Not in use
Current pager:          /usr/bin/less
Using outfile:          ''
Using delimiter:        ;
Server version:         5.1.70-log Gentoo Linux mysql-5.1.70
Protocol version:       10
Connection:             Localhost via UNIX socket
Server characterset:    latin1
Db     characterset:    utf8
Client characterset:    latin1
Conn.  characterset:    latin1
UNIX socket:            /var/run/mysqld/mysqld.sock
Uptime:                 4 min 54 sec

Threads: 16  Questions: 13589  Slow queries: 0  Opens: 1832  Flush tables: 1  Open tables: 100  Queries per second avg: 46.221

According to phpmyadmin, all my mythconverg tables are in "utf8_general_ci". I did some googling around this issue and wanted to see if the stored data is a multi-byte character set as it should be (see http://www.oreillynet.com/lpt/wlg/9022 ).

mysql> select description from recorded where title='New Girl' and subtitle ='Bachelorette Party' and LENGTH(description) != CHAR_LENGTH(description);
+--------------------------------------------------------------------------------------------------------------------------+
| description                                                                                                              |
+--------------------------------------------------------------------------------------------------------------------------+
| Jess plans to throw a bachelorette party for Cece while Nick and Winston spend some 'guy time' with her fiance Shivrang. |
+--------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

I'm not sure if any of the above proves it or not (I've barely used mysql before), but I think it might show that there is UTF8 in the UTF8-collated table (although my terminal messes up the accented e during display).

I then tried this:

mysql> set NAMES latin1;
Query OK, 0 rows affected (0.00 sec)
mysql> select description, HEX(description) from recorded where title='New Girl' and subtitle ='Bachelorette Party';
mysql> set NAMES utf8;
mysql> select description, HEX(description) from recorded where title='New Girl' and subtitle ='Bachelorette Party';

The output of the HEX(description) column for both of these commands is identical:

4A65737320706C616E7320746F207468726F7720612062616368656C6F726574746520706172747920666F722043656365207768696C65204E69636B20616E642057696E73746F6E207370656E6420736F6D6520276775792074696D6527207769746820686572206669616E63C3A9205368697672616E672E

Analysing the last part of that string, I think it is using C3 A9 for the accented 'e' in there:

i  t  h     h  e  r     f  i  a  n  c   e            S  h  i  v  r  a  n  g  .
69 74 68 20 68 65 72 20 66 69 61 6E 63 <C3 A9   > 20 53 68 69 76 72 61 6E 67 2E

I only run mythconverg on this host. The configured mysql encodings are pretty much whatever was in the original mysql configuration file I copied from the internet somewhere (when I set up the mythtv system I didn't really know what I was doing mysql-wise; still don't for the most part). The only time I've fiddled with these settings was when I did the 0.21 to 0.22 upgrade which had latin8 data stored in utf8 tables (or something like that) and needed correction. However the above recording was created long after this upgrade.

I do have an en_GB.UTF-8 locale defined on my system (along with an ISO-8859-1 one), although oddly my LANG is configured only as 'en_GB' so I'm not sure if my system is actually using UTF8 for terminals etc (which I would expect it to be really). I will look into fixing that, but will hold off until we've finished the diagnosis here unless otherwise instructed.

billmeek commented 10 years ago

Before going any further, are you in a position to try the beta? Your Android device has to be on Ice Cream Sandwich (4.0.x) or higher.

If not, then I'd try this (trying to prove where the conversion from C3 A9 to e9 is happening:)

tee /tmp/utf8.test
select description from recorded where title='New Girl' and subtitle ='Bachelorette Party';

Then hd /tmp/utf8.test and see if the output is still properly encoded.

Speckto commented 10 years ago

I've now tried the beta on the same Device (Nexus 10, Android 4.3) - that's quite a face lift. I still see no recordings, and "monitor" shows several occurrences of the same/a similar crash (except this time it appears before I directly tap the recordings tab; presumably the app retrieves the data on startup):

10-13 18:51:16.869: D/UpcomingDownloadService(8045): onHandleIntent : enter
10-13 18:51:16.874: I/UpcomingDownloadService(8045): onHandleIntent : DOWNLOAD action selected
10-13 18:51:16.879: V/UpcomingHelperV26(8045): process : enter
10-13 18:51:17.404: D/dalvikvm(8045): GC_CONCURRENT freed 184K, 3% free 10724K/10952K, paused 2ms+1ms, total 28ms
10-13 18:51:17.409: V/UpcomingHelperV26(8045): downloadUpcoming : enter
10-13 18:51:17.414: D/UpcomingHelperV26(8045): downloadUpcoming : etag=null
10-13 18:51:17.519: D/dalvikvm(8045): GC_CONCURRENT freed 404K, 4% free 10859K/11300K, paused 2ms+1ms, total 26ms
10-13 18:51:17.609: D/dalvikvm(8045): GC_CONCURRENT freed 542K, 5% free 10967K/11544K, paused 1ms+1ms, total 18ms
10-13 18:51:17.664: D/dalvikvm(8045): GC_CONCURRENT freed 718K, 7% free 10942K/11696K, paused 1ms+2ms, total 18ms
10-13 18:51:17.664: D/dalvikvm(8045): WAIT_FOR_CONCURRENT_GC blocked 4ms
10-13 18:51:17.724: D/dalvikvm(8045): GC_CONCURRENT freed 598K, 7% free 10935K/11696K, paused 1ms+1ms, total 19ms
10-13 18:51:19.299: D/dalvikvm(8045): GC_CONCURRENT freed 484K, 6% free 11034K/11696K, paused 2ms+2ms, total 22ms
10-13 18:51:19.384: E/UpcomingHelperV26(8045): process : error
10-13 18:51:19.384: E/UpcomingHelperV26(8045): org.mythtv.services.api.MythServiceApiRuntimeException: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]; nested exception is org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.mythtv.services.api.v026.impl.DvrTemplate.getRecordedList(DvrTemplate.java:352)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.mythtv.service.dvr.v26.UpcomingHelperV26.downloadUpcoming(UpcomingHelperV26.java:126)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.mythtv.service.dvr.v26.UpcomingHelperV26.process(UpcomingHelperV26.java:106)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.mythtv.service.dvr.UpcomingDownloadService.onHandleIntent(UpcomingDownloadService.java:89)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:65)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at android.os.Handler.dispatchMessage(Handler.java:99)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at android.os.Looper.loop(Looper.java:137)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at android.os.HandlerThread.run(HandlerThread.java:61)
10-13 18:51:19.384: E/UpcomingHelperV26(8045): Caused by: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.http.converter.json.MappingJackson2HttpMessageConverter.readInternal(MappingJackson2HttpMessageConverter.java:126)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.http.converter.AbstractHttpMessageConverter.read(AbstractHttpMessageConverter.java:147)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.web.client.HttpMessageConverterExtractor.extractData(HttpMessageConverterExtractor.java:76)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.web.client.RestTemplate$ResponseEntityResponseExtractor.extractData(RestTemplate.java:655)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.web.client.RestTemplate$ResponseEntityResponseExtractor.extractData(RestTemplate.java:641)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:484)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:453)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:429)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at org.mythtv.services.api.v026.impl.DvrTemplate.getRecordedList(DvrTemplate.java:347)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  ... 7 more
10-13 18:51:19.384: E/UpcomingHelperV26(8045): Caused by: com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at [Source: java.util.zip.GZIPInputStream@41f83d40; line: 1, column: 100546]
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1378)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:599)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._reportInvalidOther(UTF8StreamJsonParser.java:3014)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._reportInvalidOther(UTF8StreamJsonParser.java:3021)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._decodeUtf8_3fast(UTF8StreamJsonParser.java:2843)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString2(UTF8StreamJsonParser.java:2143)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString(UTF8StreamJsonParser.java:2092)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.getValueAsString(UTF8StreamJsonParser.java:291)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:24)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:11)
10-13 18:51:19.384: E/UpcomingHelperV26(8045):  at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java
10-13 18:51:19.384: V/UpcomingHelperV26(8045): process : enter
10-13 18:51:19.389: D/UpcomingDownloadService(8045): onHandleIntent : exit
10-13 18:51:19.389: V/BackendStatusFragment(7832): UpcomingDownloadReceiver.onReceive : enter
10-13 18:51:19.389: I/BackendStatusFragment(7832): UpcomingDownloadReceiver.onReceive : Upcoming Programs Download Service Finished
10-13 18:51:19.389: V/RunningServiceHelper(7832): isServiceRunning : enter
10-13 18:51:19.389: D/RunningServiceHelper(7832): isServiceRunning : checking for running server 'org.mythtv.service.dvr.RecordingRuleService'
10-13 18:51:19.389: V/RunningServiceHelper(7832): isServiceRunning : exit
10-13 18:51:19.394: V/BackendStatusFragment(7832): UpcomingDownloadReceiver.onReceive : exit
10-13 18:51:19.394: I/ActivityManager(366): Start proc org.mythtv:recordingRule for service org.mythtv/.service.dvr.RecordingRuleService: pid=8059 uid=10080 gids={50080, 3003, 1015, 1028}
10-13 18:51:19.414: V/MainApplication(8059): onCreate : enter

I ran the test you suggested (although I used xxd not hd) and it looks like the character is being converted correctly:

00001d0: 2d2d 2d2d 2d2d 2b0a 7c20 4a65 7373 2070  ------+.| Jess p
00001e0: 6c61 6e73 2074 6f20 7468 726f 7720 6120  lans to throw a
00001f0: 6261 6368 656c 6f72 6574 7465 2070 6172  bachelorette par
0000200: 7479 2066 6f72 2043 6563 6520 7768 696c  ty for Cece whil
0000210: 6520 4e69 636b 2061 6e64 2057 696e 7374  e Nick and Winst
0000220: 6f6e 2073 7065 6e64 2073 6f6d 6520 2767  on spend some 'g
0000230: 7579 2074 696d 6527 2077 6974 6820 6865  uy time' with he
0000240: 7220 6669 616e 63e9 2053 6869 7672 616e  r fianc. Shivran
0000250: 672e 207c 0a2b 2d2d 2d2d 2d2d 2d2d 2d2d  g. |.+----------

So marking that up a bit for ease

         r    f i  a n  c é    S  h i  v r  a  n
0000240: 7220 6669 616e 63e9 2053 6869 7672 616e |r fianc. Shivran

For completeness I repeated this test after having executed 'set NAMES utf8' and verified that 'C3 A9' appeared.

Speckto commented 10 years ago

With the beta, I get a repeatable crash on exit if I do the following:

  1. Start the application and allow it to load the home screen (with the upcoming recordings, and recording status)
  2. Tap the myth icon in the top left, select 'DVR' from the actions screen (this drops me at my blank recordings screen)
  3. Tap the myth icon in the top left, Select 'Guide' from the side bar
  4. Tap the myth icon in the top left, Select 'Recordings' from the side bar
  5. Tap the home button. The application hides then I get "Unfortunately MythTV android Frontend has stopped". There is a null pointer exception in the log file. I've uploaded a log from that session here: http://random.divergentlocus.co.uk/filedump/myth-exit-crash-pid.txt Do you want me to raise this as a separate issue/ticket against the beta?

edit: Version number listed next to MAF is 1.20.0 - installed from play store about 10 minutes ago.

billmeek commented 10 years ago

1st, thanks for testing the beta. I was concerned because the developers are doing all of the work there, not in 1.10.x.

If I"m reading this correctly, in the DB, c3 a9 = é. In the above, it's stored as e9 which should be the start of a three byte sequence (1110xxxx 10xxxxxx 10xxxxxx.)

When you set NAMES utf8 the result is correct, which is only for the current session? I'll google around and see if there's something to do, perhaps what I've got in mine:

Client characterset:    utf8
Conn.  characterset:    utf8

vs.

Client characterset:    latin1
Conn.  characterset:    latin1

My backend starts like this: LANG=$LANG LC_CTYPE=$LANG /usr/local/bin/mythbackend Where both are set to en_US.UTF-8.

I haven't labeled this as a bug yet, because I don't know if JSON can ignore the data. Since you have several of these, you could go into the MythTV metadata editor on the frontend and remove the é. It can always be put back.

And, yes, please open a new issue with the above in it, thanks again (I tried it on my tablet, but it didn't fire.)

Speckto commented 10 years ago

OK. I'll open another issue for that crash. Potentially that crash only occurs where my earlier crash has happened. I'll stick with the beta for the moment as it seems about as functional as the previous version for me :)

I appreciate that there may not be a lot that the android front-end can do if it is sent invalid data. Of course ideally it would ignore that recording, display the rest and display a list of errors. As you say that may not be possible. What was getting me about this before was there wasn't an error - the application just stated "I've got all the recordings fine". From a usability perspective an error message would be nice. I raised this issue because I didn't really know where to look next (e.g. get the exact data the android front-end uses, etc) and you've helped me progress this - thanks!

According to the mysql manual, set names tells the server that the character set the connected client is using. I'm not a mysql expert - I just pulled the command from the oreilly page. See http://dev.mysql.com/doc/refman/5.0/en/charset-connection.html

Even if this isn't eventually raised as a bug, I'm at least hoping I can reconfigure the system to fix this. So far we've identified some potentially changes I could make:

  1. Changing the client/conn. charset in mysql configuration
  2. Making sure my system locale is based on UTF8 properly
  3. Remove the offending characters..temporary until some other recording causes another issue like this (the metadata is broadcast over the air). Let me know if you'd like me to start fiddling with these; I don't want to start doing this until you have all the diagnostic information you want.

My backend doesn't appear to have any special settings/environment variables when executed, but I'm not massively sure on this.

I'm wondering if mysql is converting the data just fine, and this is a mythbackend bug. Perhaps as part of the mythtv encoding to JSON format it assumes the data is already in UTF8 format and requires no conversion when it isn't (it might be latin8). Clearly the xml output code converts correctly. I don't know anything about the mythtv codeso wouldn't really know where to start looking. I also have no idea what connection settings the backend would use - it might explicitly request usage of UTF8 in all cases.

billmeek commented 10 years ago

I just added the é to one of my recordings and refreshed my screen. No failure. I haven't found a reference that says what mysql should be set to. I know that Mike Dean has discussed it on the mythtv-users mailing list, and can find notes that say after 0.22 it shouldn't be a problem. I agree that the app should handle errors, I just don't know if this one can be.

Note, the é displayed in both MythTV and in MAF A-OK. Does MythTV display the é in the frontend for you? I'd go ahead and remove them just to be sure we're on the right path (very bad if it didn't!!!) I remember 3 instances in the descriptions and one title (DeJaVu, with an accent.)

Speckto commented 10 years ago

Yes mythfrontend displays the accented e and the De Ja Vu title without problem.

I'll start working on editing out the accented characters in the database and experimenting with my system configuration a little bit in a reversible way.

billmeek commented 10 years ago

I'd suggest using the frontend metadata editor, just 'cause it's safer. If you haven't used it, on a recording, press m, select Recording Options then Change Recording Metadata. You can change the title and description there.

Speckto commented 10 years ago

Good news: Removing the accented characters from the metadata (using the editor as you suggested) allowed MAF to display my recordings! I even managed to play back an episode!

I then cleared MAF's cache and re-added the accented e to one of them - once again MAF failed to download any recordings (even after I hit refresh) - although I didn't check the android log to confirm why. Removing the character and hitting refresh again presented me with a populated recordings screen.

I tried changing the mysql configuration to use all UFT8, but that doesn't seem to solve the problem - MAF still cannot access my recordings in this case. Checking the mythtv log file (which I happened to do after restarting the backend), it appears to be starting with my locale of en_GB - rather than using en_GB.UTF8 so I've no idea what encoding it is using by default. There is also a rather ominous message:

2013-10-14 21:18:21.786841 I [21800/21800] CoreContext mythcorecontext.cpp:231 (Init) - Assumed character encoding: en_GB
2013-10-14 21:18:21.786850 W [21800/21800] CoreContext mythcorecontext.cpp:238 (Init) - This application expects to be running a locale that specifies a UTF-8 codeset, and many features may behave improperly with your current language settings. Please set the LC_ALL or LC_CTYPE, and LANG variable(s) in the environment in which this program is executed to include a UTF-8 codeset (such as 'en_US.UTF-8').

So I think my next step is to switch the backend (probably along with my entire environment) to using UTF8 and see if that allows proper use of multi-byte characters. (Given I've now noticed I'm not using UTF8 when I thought I was I'd probably do this at some point anyway). Let me know if you think we should do any further investigation before I do this - .happy to wait.

billmeek commented 10 years ago

@dmfrey, any way to absorb the bad data and prevent the crash?

I can add a Wiki item about this, but the ideal would be if the app could detect the error and warn the user (I know pie meet sky.) Maybe this is a start: http://stackoverflow.com/questions/3715264/how-to-handle-user-input-of-invalid-utf-8-characters

@Speckto:

Good to know that we're trying to solve the correct problem. Thanks for doing that!

Here's what I do (in part) to start my backend:

test -f /etc/default/locale && . /etc/default/locale || true
LANG=$LANG LC_CTYPE=$LANG exec /usr/local/bin/mythbackend 

But that's how Ubuntu does it. There was much discussion on the mythtv-users list awhile ago about LANG and LC_TYPE. There are some cases where only one is needed, others need both. I can't remember the details, but using both causes no harm.

/etc/defaults/local holds the proper settings on my machine, so sourcing it in the startup script works A-OK. If you don't have such a file, then just set them manually to en_GB.UTF8.

billmeek commented 10 years ago

When I test this without setting LANG/LC_TYPE, the letter é simply doesn't display (before the commit above.) So, I still don't know the root cause of this and will have to let @Speckto, test when 1.20.2 is released.

billmeek commented 10 years ago

@Speckto, 1.20.2 was released at about 1300UTC so it should show up on your device in a few hours. This was relabeled a bug, but see Dan's note 2 comments above this. Thanks for testing.

billmeek commented 10 years ago

@Speckto, I also tried setting my LANG/LC_TYPE to only en_GB and didn't get a failure. But you should be the final judge on this issue.

Please retry with 1.20.2. I know you already tested 230. Thanks!

Speckto commented 10 years ago

So I retested this issue (without any character set reconfiguration) using the latest beta. I'm not likely to get around to testing with mythbackend working in different character sets until the weekend.

I still don't see any recordings (which from Dan's note is expected) - I understand that there isn't anything you can do to fix the parsing. That makes sense.

What happens: I see a blank recordings screen. If I click the refresh icon it spins for a bit before stopping (still no recordings displayed).

I was surprised to see that there is still no error message displayed in the app - it fails silently. The log file shows that a MythServicesApiRuntimeException is being thrown now (see below).

Is this the expected behaviour with the beta or were you expecting to see some sort of error message? If this quite a rare issue, then perhaps it isn't worth the effort doing that (assuming it is even possible) - but I thought it best to confirm..

The new crash in case you are interested:

10-16 20:13:30.174: D/RecordedService(5090): onHandleIntent : enter
10-16 20:13:30.179: I/RecordedService(5090): onHandleIntent : DOWNLOAD action selected
10-16 20:13:30.189: V/RecordedHelperV26(5090): process : enter
10-16 20:13:30.319: D/dalvikvm(5090): GC_CONCURRENT freed 198K, 3% free 10599K/10840K, paused 3ms+2ms, total 32ms
10-16 20:13:30.404: V/RecordedHelperV26(5090): downloadRecorded : enter
10-16 20:13:30.409: D/RecordedHelperV26(5090): downloadRecorded : etag=null
10-16 20:13:30.489: D/dalvikvm(5090): GC_CONCURRENT freed 331K, 4% free 10836K/11204K, paused 3ms+3ms, total 43ms
10-16 20:13:30.489: D/dalvikvm(5090): WAIT_FOR_CONCURRENT_GC blocked 6ms
10-16 20:13:30.629: D/dalvikvm(5090): GC_CONCURRENT freed 571K, 6% free 10901K/11504K, paused 1ms+3ms, total 33ms
10-16 20:13:30.714: D/dalvikvm(5090): GC_CONCURRENT freed 612K, 6% free 10960K/11608K, paused 1ms+2ms, total 24ms
10-16 20:13:30.714: D/dalvikvm(5090): WAIT_FOR_CONCURRENT_GC blocked 7ms
10-16 20:13:30.824: D/dalvikvm(5090): GC_CONCURRENT freed 661K, 6% free 10991K/11688K, paused 2ms+5ms, total 33ms
10-16 20:13:30.824: D/dalvikvm(5090): WAIT_FOR_CONCURRENT_GC blocked 13ms
10-16 20:13:31.909: D/dalvikvm(5090): GC_CONCURRENT freed 593K, 6% free 11033K/11688K, paused 1ms+2ms, total 27ms
10-16 20:13:32.069: E/RecordedHelperV26(5090): process : error
10-16 20:13:32.069: E/RecordedHelperV26(5090): org.mythtv.services.api.MythServiceApiRuntimeException: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]; nested exception is org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.mythtv.services.api.v026.impl.DvrTemplate.getRecordedList(DvrTemplate.java:352)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.mythtv.service.dvr.v26.RecordedHelperV26.downloadRecorded(RecordedHelperV26.java:204)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.mythtv.service.dvr.v26.RecordedHelperV26.process(RecordedHelperV26.java:126)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.mythtv.service.dvr.RecordedService.onHandleIntent(RecordedService.java:103)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:65)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at android.os.Handler.dispatchMessage(Handler.java:99)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at android.os.Looper.loop(Looper.java:137)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at android.os.HandlerThread.run(HandlerThread.java:61)
10-16 20:13:32.069: E/RecordedHelperV26(5090): Caused by: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]; nested exception is com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.http.converter.json.MappingJackson2HttpMessageConverter.readInternal(MappingJackson2HttpMessageConverter.java:126)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.http.converter.AbstractHttpMessageConverter.read(AbstractHttpMessageConverter.java:147)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.web.client.HttpMessageConverterExtractor.extractData(HttpMessageConverterExtractor.java:76)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.web.client.RestTemplate$ResponseEntityResponseExtractor.extractData(RestTemplate.java:655)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.web.client.RestTemplate$ResponseEntityResponseExtractor.extractData(RestTemplate.java:641)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:484)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:453)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:429)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at org.mythtv.services.api.v026.impl.DvrTemplate.getRecordedList(DvrTemplate.java:347)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  ... 7 more
10-16 20:13:32.069: E/RecordedHelperV26(5090): Caused by: com.fasterxml.jackson.core.JsonParseException: Invalid UTF-8 middle byte 0x20
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at [Source: java.util.zip.GZIPInputStream@41fd1a10; line: 1, column: 140821]
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1378)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:599)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._reportInvalidOther(UTF8StreamJsonParser.java:3014)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._reportInvalidOther(UTF8StreamJsonParser.java:3021)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._decodeUtf8_3fast(UTF8StreamJsonParser.java:2843)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString2(UTF8StreamJsonParser.java:2143)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString(UTF8StreamJsonParser.java:2092)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.getValueAsString(UTF8StreamJsonParser.java:291)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:24)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:11)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:375)
10-16 20:13:32.069: E/RecordedHelperV26(5090):  at com.f
10-16 20:13:32.069: V/RecordedHelperV26(5090): process : exit
10-16 20:13:32.069: I/RecordingsFragment(4914): RecordedDownloadReceiver.onReceive : enter
10-16 20:13:32.069: I/RecordingsFragment(4914): RecordedDownloadReceiver.onReceive : complete=Recorded Programs Download Service Finished
10-16 20:13:32.069: I/RecordingsFragment(4914): RecordedDownloadReceiver.onReceive : exit
10-16 20:13:32.069: I/EpisodeFragment(4914): RecordedRemovedReceiver.onReceive : enter
10-16 20:13:32.069: I/EpisodeFragment(4914): RecordedRemovedReceiver.onReceive : complete=Recorded Programs Download Service Finished
10-16 20:13:32.069: V/RecordingsParentFragment(4914): onEpisodeDeleted : enter
10-16 20:13:32.069: V/RecordingsFragment(4914): notifyDeleted : enter
10-16 20:13:32.069: V/RecordingsFragment(4914): onCreateLoader : enter
10-16 20:13:32.069: V/RecordingsFragment(4914): onCreateLoader : exit
10-16 20:13:32.069: V/RecordingsFragment(4914): notifyDeleted : exit
10-16 20:13:32.069: V/ProgramGroupDaoHelper(4914): findOne : enter
10-16 20:13:32.074: V/ProgramGroupDaoHelper(4914): findOne : exit
10-16 20:13:32.074: V/RecordingsParentFragment(4914): onEpisodeDeleted : exit
10-16 20:13:32.074: I/EpisodeFragment(4914): RecordedRemovedReceiver.onReceive : exit
10-16 20:13:32.079: D/dalvikvm(5090): GC_CONCURRENT freed 729K, 7% free 11002K/11776K, paused 2ms+2ms, total 27ms
10-16 20:13:32.084: D/RecordedService(5090): onHandleIntent : exit
10-16 20:13:32.149: D/dalvikvm(366): GC_EXPLICIT freed 1910K, 23% free 28279K/36312K, paused 2ms+7ms, total 71ms
10-16 20:13:32.154: V/RecordingsFragment(4914): onLoadFinished : enter
10-16 20:13:32.154: V/RecordingsFragment(4914): onLoadFinished : exit
billmeek commented 10 years ago

@Speckto, thanks for the input. Looking back over these notes, you mentioned having ISO-8859 on your system. I found this: http://en.wikipedia.org/wiki/ISO/IEC_8859 which shows é=1110 1001=233=0xE9. So perhaps that's the reason for the incorrect conversion. Nothing I've changed so far has duplicated the problem.

At your convenience, I'd appreciate it if you would try this modified wget

wget \
   --server-response \
   --header='Accept: application/json' \
   --header='Accept-Encoding: gzip' \
   --output-document=/tmp/JsonData.gz \
   <yourBackendHostname>:6544/Dvr/GetRecordedList?Descending=true

No need to examine the JsonData.gz, but I'd like to know if the header in the response contains anything remotely like this: Content-Type: text/json; charset=iso-8859-1. If it shows up there, I think it could be detected and the user warned about it.

Speckto commented 10 years ago

Doesn't look like it includes the charset unfortunately. Incidentally, I wasn't saying it had to give the exact reason for the failure in any error message - more that it would be good if it explicitly stated something was wrong even if it cannot identify the cause. Since it already fails gracefully (doesn't actually crash) it may not be be worthwhile doing this.

--2013-10-17 20:02:10--  http://192.168.0.75:6544/Dvr/GetRecordedList?Descending=true
Connecting to 192.168.0.75:6544... connected.
HTTP request sent, awaiting response...
  HTTP/1.1 200 OK
  Date: 17 Oct 2013 19:02:11
  Server: Linux 3.2.12-gentoo, UPnP/1.0, MythTV 0.26.20130225-1
  Accept-Ranges: bytes
  Cache-Control: no-cache="Ext", max-age = 5000
  Content-Encoding: gzip
  ETag: "48bd41fefc7e253a1a6325f28c92af4fb1b71768"
  Connection: Keep-Alive
  Content-Type: application/json
  Content-Length: 46895
Length: 46895 (46K) [application/json]
Saving to: 'tempJsonData.gz'

100%[=================================================================================================================================>] 46,895      --.-K/s   in 0s

2013-10-17 20:02:11 (142 MB/s) - 'tempJsonData.gz' saved [46895/46895]
billmeek commented 10 years ago

I appreciate your checking. Plan C, if changing LANG/LC_TYPE works would be to modify a patch for Mythtv http://code.mythtv.org/trac/ticket/11386 . And, add a check for those two variables. What I'd like is for any app to refuse to run if the backend had configuration issues (and in our case, automatically send users to our Wiki and put instructions there.)

@dmfrey, the patch hasn't gotten any attention, so I'm not hopeful. Plus, at the very best, it would only show up in 0.28. Are the exceptions caught by your fixs too 'deep' to allow MAF to alert the user about them?

dmfrey commented 10 years ago

we are now catching the mythtv api runtime exceptions. Form that object we should be able to inspect any child exceptions. From there we should be able to check that a low level exception occurred and provide a message accordingly.

On Thu, Oct 17, 2013 at 3:26 PM, billmeek notifications@github.com wrote:

I appreciate your checking. Plan C, if changing LANG/LC_TYPE works would be to modify a patch for Mythtv http://code.mythtv.org/trac/ticket/11386 . And, add a check for those two variables. What I'd like is for any app to refuse to run if the backend had configuration issues (and in our case, automatically send users to our Wiki and put instructions there.)

@dmfrey https://github.com/dmfrey, the patch hasn't gotten any attention, so I'm not hopeful. Plus, at the very best, it would only show up in 0.28. Are the exceptions caught by your fixs too 'deep' to allow MAF to alert the user about them?

— Reply to this email directly or view it on GitHubhttps://github.com/MythTV-Clients/MythTV-Android-Frontend/issues/219#issuecomment-26540899 .

My Google Profile http://www.google.com/profiles/dmfrey

billmeek commented 10 years ago

Finally! Got my system to fail. In order to see the blank recordings page, it was necessary to go to Android Settings->Applications->MAF and stop MAF, clear cache, delete the data after doing the following on my backend and then rebooting the backend (for good measure.)

In /etc/default/locale, all lines were left 'normal':
LANG=en_US.UTF-8

/var/lib/locales/supported.d/local I added the 2nd line:
en_US.UTF-8 UTF-8
en_US.ISO-8859-1 ISO-8859-1

And the backend was started with this:
LANG="en_US.ISO-8859-1" LC_CTYPE="en_US.ISO-8859-1" /usr/local/bin/mythbackend

The 1st two lines of the error in LogCat are:

10-17 20:42:41.632: E/RecordedHelperV26(10840): process : error
10-17 20:42:41.632: E/RecordedHelperV26(10840): org.mythtv.services.api.MythServiceApiRuntimeException: org.springframework.http.converter.HttpMessageNotReadableException: Could not read JSON: Invalid UTF-8 middle byte 0x29

@dmfrey, could the 2nd line of the above be checked for "Invalid UTF-8" and an error be displayed. I could give detailed instructions in the Wiki.

@Speckto, I'm comfortable saying this is a backend configuration issue. But MAF would do well to notify the user, so I'm leaving the bug label (and design discussion and enhancement.)

If you get a chance, I think you can solve the problem by just starting the backend with: LANG="en_GB.UTF8" LC_CTYPE=$LANG /usr/local/bin/mythbackend ... You get to decide if/when to push the "Close & Comment" button.

Thanks for hanging in there with us.

billmeek commented 10 years ago

@dmfrey Eclipse is happy with the following in service/dvr/v26/RecordedHelperV26.java but when the error is detected the BadTokenException fires, hints welcome...

10-18 15:29:09.007: E/RecordedHelperV26(13944): INVALID UTF-8 DETECTED!!! Try to open a Progress Dialog, context='org.mythtv.service.dvr.RecordedService@417ec2f0'
10-18 15:29:09.164: E/RecordedService(13944): onHandleIntent : error
10-18 15:29:09.164: E/RecordedService(13944): android.view.WindowManager$BadTokenException: Unable to add window -- token null is not for an application
10-18 15:29:09.164: E/RecordedService(13944):   at android.view.ViewRootImpl.setView(ViewRootImpl.java:697)

The new code is in the catch {} about half way down...

    public boolean process( final Context context, final LocationProfile locationProfile ) {
        Log.v( TAG, "process : enter" );

        if( !NetworkHelper.getInstance().isMasterBackendConnected( context, locationProfile ) ) {
            Log.w( TAG, "process : Master Backend '" + locationProfile.getHostname() + "' is unreachable" );

            return false;
        }

        mMythServicesTemplate = (MythServicesTemplate) MythAccessFactory.getServiceTemplateApiByVersion( mApiVersion, locationProfile.getUrl() );
        if( null == mMythServicesTemplate ) {
            Log.w( TAG, "process : Master Backend '" + locationProfile.getHostname() + "' is unreachable" );

            return false;
        }

        boolean passed = true;

        try {

            downloadRecorded( context, locationProfile );

        } catch( Exception e ) {
            Log.e( TAG, "process : error", e );

            if( e.toString().contains( "Invalid UTF-8" ) ) {
                // IF THIS WORKS, ADD REAL STRINGS!!!
                Log.e( TAG, "INVALID UTF-8 DETECTED!!! Try to open a Progress Dialog, context='" + context + "'" );
                mProgressDialog = new ProgressDialog( context );
                mProgressDialog.setTitle( context.getResources().getString( R.string.gallery_sg_exist_create )  );
                mProgressDialog.setMessage( context.getResources().getString( R.string.gallery_sg_exist_create ) );
                mProgressDialog.setCancelable(false);
                mProgressDialog.setButton(DialogInterface.BUTTON_NEGATIVE, context.getResources().getString( R.string.gallery_sg_exist_create ), new DialogInterface.OnClickListener() {
                    @Override
                    public void onClick(DialogInterface dialog, int which) {
                        dialog.dismiss();
                    }
                });
                mProgressDialog.show();
            }

            passed = false;
        }

        Log.v( TAG, "process : exit" );
        return passed;
    }
Speckto commented 10 years ago

I can confirm that changing the init.d script for mythbackend to explicitly set the LANG and LC_CTYPE to en_GB.UTF8 resolves the issue and the recordings work even with accented characters.

Switching my backend environment to use UTF8 primarily also resolves this issue for me.

I entirely agree that this is a backend configuration issue. This kind of thing is one of the risks of configuring a distro like Gentoo without knowing what you are doing - but that was kind of the point originally: to learn how Linux slots together :)

Thank-you for your assistance with tracking down the cause of this!

Having MAF display an error when this occurs would be extremely useful in case someone else hits this issue.

When do you usually close issues like this? Do you usually leave them open until a fix has been submitted to the code and has been tested?

If so, I'll leave it open until that has occurred unless you want me to do otherwise. Let me know once a fix is in a beta/release and I'll happily retest this.

dmfrey commented 10 years ago

Am I remembering this correctly @speckto, but did you previously say that this machine has been upgraded from .21 or .22, etc?

I am wondering if this was just left over from old configuration. I believe the final switch over in mythtv was either .25 or .26, but I am wondering if that config was just left alone by the scripts and never moved to UTF-8.

On Sat, Oct 19, 2013 at 8:41 AM, Speckto notifications@github.com wrote:

I can confirm that changing the init.d script for mythbackend to explicitly set the LANG and LC_CTYPE to en_GB.UTF8 resolves the issue and the recordings work even with accented characters.

Switching my backend environment to use UTF8 primarily also resolves this issue for me.

I entirely agree that this is a backend configuration issue. This kind of thing is one of the risks of configuring a distro like Gentoo without knowing what you are doing - but that was kind of the point originally: to learn how Linux slots together :)

Thank-you for your assistance with tracking down the cause of this!

Having MAF display an error when this occurs would be extremely useful in case someone else hits this issue.

When do you usually close issues like this? Do you usually leave them open until a fix has been submitted to the code and has been tested?

If so, I'll leave it open until that has occurred unless you want me to do otherwise. Let me know once a fix is in a beta/release and I'll happily retest this.

— Reply to this email directly or view it on GitHubhttps://github.com/MythTV-Clients/MythTV-Android-Frontend/issues/219#issuecomment-26648959 .

My Google Profile http://www.google.com/profiles/dmfrey

Speckto commented 10 years ago

Yes it was upgraded from 0.21. (possibly an earlier version than that as well). I don't think this is left-over configuration, but bad initial configuration on my part. I always intended to use UTF8 system wide from the start - I'd even added the locale - but I never actually switched to using it (mistake). Perhaps mythbackend eventually started to require use of UTF8 sometime after 0.21 but I missed that upgrade step if it did. Even if it did I wouldn't expect the myth backend upgrade to reconfigure my system for me, just warn me there was an issue.

dmfrey commented 10 years ago

Ah, gotcha. I thought maybe this would have been in the myth scripts somewhere, not dependent on the user to make this specific change. I am glad it is working for you.

@billmeek we should come up with a workflow to add into the app to alert users of these types of config changes they might need to make. Probably when we check the myth version when setting up the location profile. I am open to thoughts. IMO, the whole location profile needs an overhaul anyway as it was carryover from the prior way Android did preferences.

On Sat, Oct 19, 2013 at 8:53 AM, Speckto notifications@github.com wrote:

Yes it was upgraded from 0.21. (possibly an earlier version than that as well). I don't think this is left-over configuration, but bad initial configuration on my part. I always intended to use UTF8 system wide from the start - I'd even added the locale - but I never actually switched to using it (mistake). Perhaps mythbackend eventually started to require use of UTF8 sometime after 0.21 but I missed that upgrade step if it did. Even if it did I wouldn't expect the myth backend upgrade to reconfigure my system for me, just warn me there was an issue.

— Reply to this email directly or view it on GitHubhttps://github.com/MythTV-Clients/MythTV-Android-Frontend/issues/219#issuecomment-26649153 .

My Google Profile http://www.google.com/profiles/dmfrey

billmeek commented 10 years ago

@Speckto, thanks for testing the configuration on your BE. Normally, I like the person who opened the issue to close it. However, now that I can duplicate it and you've proven the root cause. I'll close it. There will be a new issue to track an enhancement that would provide notification to the MAF user.

@dmfrey, agreed, I'll respond off-list with some ideas.