Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

No recordings displayed on recordings screen #219

Closed
Speckto opened this issue Oct 9, 2013 · 31 comments
Closed

No recordings displayed on recordings screen #219

Speckto opened this issue Oct 9, 2013 · 31 comments
Assignees
Labels
Milestone

Comments

@Speckto
Copy link

Speckto commented Oct 9, 2013

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

@ghost ghost assigned dmfrey Oct 9, 2013
@billmeek
Copy link
Contributor

billmeek commented Oct 9, 2013

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
Copy link
Contributor

@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
Copy link
Author

Speckto commented Oct 10, 2013

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
Copy link
Contributor

@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
Copy link
Contributor

@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
Copy link
Author

Speckto commented Oct 13, 2013

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
Copy link
Contributor

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
Copy link
Author

Speckto commented Oct 13, 2013

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
Copy link
Author

Speckto commented Oct 13, 2013

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
Copy link
Contributor

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
Copy link
Author

Speckto commented Oct 13, 2013

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
Copy link
Contributor

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
Copy link
Author

Speckto commented Oct 13, 2013

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
Copy link
Contributor

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
Copy link
Author

Speckto commented Oct 14, 2013

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
Copy link
Contributor

@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.

dmfrey pushed a commit that referenced this issue Oct 15, 2013
I added some catches in for the MythServicesApiRuntimeException.

Unfortunately, i think the only thing we can do at this point is allow
it to fail gracefully.  If the incoming data isn't completed or
unparsable in any way, I don't think it can partially proceed.  These
parsing exceptions are at too deep a level to allow the app to try to
access any of the data and load it.
@billmeek
Copy link
Contributor

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
Copy link
Contributor

@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
Copy link
Contributor

@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
Copy link
Author

Speckto commented Oct 16, 2013

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
Copy link
Contributor

@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
Copy link
Author

Speckto commented Oct 17, 2013

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
Copy link
Contributor

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
Copy link
Contributor

dmfrey commented Oct 17, 2013

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 [email protected] 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//issues/219#issuecomment-26540899
.

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

@billmeek
Copy link
Contributor

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
Copy link
Contributor

@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
Copy link
Author

Speckto commented Oct 19, 2013

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
Copy link
Contributor

dmfrey commented Oct 19, 2013

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 [email protected] 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//issues/219#issuecomment-26648959
.

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

@Speckto
Copy link
Author

Speckto commented Oct 19, 2013

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
Copy link
Contributor

dmfrey commented Oct 19, 2013

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 [email protected] 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//issues/219#issuecomment-26649153
.

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

@billmeek
Copy link
Contributor

@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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants