Ticket #10083: log

File log, 13.3 KB (added by Ken Mandelberg <km@…>, 11 years ago)

output from "mythfilldatabase --refresh-all"

Line 
12011-10-07 18:56:39.421642 C  mythfilldatabase version: master [v0.25pre-3424-g998288d-dirty] www.mythtv.org
22011-10-07 18:56:39.421682 N  Enabled verbose msgs:  general
32011-10-07 18:56:39.421721 N  Setting Log Level to LOG_INFO
42011-10-07 18:56:39.421796 I  Added logging to the console
52011-10-07 18:56:39.421811 I  Added database logging to table logging
62011-10-07 18:56:39.421909 N  Setting up SIGHUP handler
72011-10-07 18:56:39.422236 N  Using runtime prefix = /usr/local
82011-10-07 18:56:39.422259 N  Using configuration directory = /home/km/.mythtv
92011-10-07 18:56:39.422347 W  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 variable(s) in the environment in which this program is executed to include a UTF-8 codeset (such as 'en_US.UTF-8').
102011-10-07 18:56:39.423607 N  Empty LocalHostName.
112011-10-07 18:56:39.423622 I  Using localhost value of maclinux
122011-10-07 18:56:39.466893 I  Database connection created: DBManager0
132011-10-07 18:56:39.466953 I  New DB connection, total: 1
142011-10-07 18:56:39.470765 I  Connected to database 'mythconverg' at host: localhost
152011-10-07 18:56:39.474576 I  Closing DB connection named 'DBManager0'
162011-10-07 18:56:39.474776 I  Database connection created: DBManager1
172011-10-07 18:56:39.474807 I  New DB connection, total: 1
182011-10-07 18:56:39.475345 I  Connected to database 'mythconverg' at host: localhost
192011-10-07 18:56:39.477060 I  Current locale EN_US
202011-10-07 18:56:39.477140 E  Reading locale defaults from /usr/local/share/mythtv//locales/en_us.xml
212011-10-07 18:56:39.490689 I  Loading en_us translation for module mythfrontend
222011-10-07 18:56:39.493662 I  Current MythTV Schema Version (DBSchemaVer): 1282
232011-10-07 18:56:39.522380 I  Database connection created: DBManager2
242011-10-07 18:56:39.522406 I  New DB connection, total: 2
252011-10-07 18:56:39.522798 I  Connected to database 'mythconverg' at host: localhost
262011-10-07 18:56:39.681904 I  Updating source #1 (zap) with grabber schedulesdirect1
272011-10-07 18:56:39.682248 I  Found 45 channels for source 1 which use grabber
282011-10-07 18:56:39.682314 I  Checking day @ offset 0, date: Fri Oct 7 2011
29--2011-10-07 18:56:39--  http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService
30Resolving webservices.schedulesdirect.tmsdatadirect.com... 2011-10-07 18:56:39.727366 N  Data is already present for Fri Oct 7 2011, skipping
312011-10-07 18:56:39.727411 I  Checking day @ offset 1, date: Sat Oct 8 2011
322011-10-07 18:56:39.727416 I  Data Refresh always needed for tomorrow
332011-10-07 18:56:39.727421 N  Refreshing data for Sat Oct 8 2011
342011-10-07 18:56:39.727478 I  This DataDirect listings source is shared by 2 MythTV lineups
352011-10-07 18:56:39.727486 N  We should keep data around after this one
362011-10-07 18:56:39.727528 I  Database connection created: DataDirectCon
372011-10-07 18:56:39.727550 I  New static DB connectionDataDirectCon
382011-10-07 18:56:39.727965 I  Connected to database 'mythconverg' at host: localhost
392011-10-07 18:56:39.729128 I  Retrieving datadirect data.
402011-10-07 18:56:39.729169 I  Grabbing data for Fri Oct 7 2011 offset 1
412011-10-07 18:56:39.729210 I  From Sat Oct 8 04:00:00 2011 to Sun Oct 9 04:00:00 2011 (UTC)
422011-10-07 18:56:39.729241 I  DataDirect: Grabbing listing data
432011-10-07 18:56:39.729783 I  Starting process manager
442011-10-07 18:56:39.732362 I  Starting IO manager (write)
452011-10-07 18:56:39.732442 I  Starting IO manager (read)
462011-10-07 18:56:39.732516 I  Starting process signal handler
47144.142.232.53
48Connecting to webservices.schedulesdirect.tmsdatadirect.com|144.142.232.53|:80... connected.
49HTTP request sent, awaiting response... 401 Unauthorized
50Connecting to webservices.schedulesdirect.tmsdatadirect.com|144.142.232.53|:80... connected.
51HTTP request sent, awaiting response... 200 OK
52Length: unspecified [text/xml]
53Saving to: `/tmp/mythtv_ddp_uXw7Zw/mythtv_dd_cache_1_km@mathcs.emory.edu_UTC_20111008040000_to_20111009040000.gz'
54
55     0K .......... .......... .......... .......... .......... 19.6K
56    50K .......... .......... .......... .......... .......... 74.0K
57   100K .......... .......... .......... .......... .......... 46.7K
58   150K .......... .......... .......... .......... .......... 26.8K
59   200K .......... .......... .......... .......... .          87.5K=6.6s
60
612011-10-07 18:56:47 (36.3 KB/s) - `/tmp/mythtv_ddp_uXw7Zw/mythtv_dd_cache_1_km@mathcs.emory.edu_UTC_20111008040000_to_20111009040000.gz' saved [246838]
62
632011-10-07 18:56:47.280035 I  DataDirect: Your subscription expires on Tue Jun 19 (2012) 10:33 PM
642011-10-07 18:56:47.411322 I  DataDirect: sourceid 3 has lineup type: CableDigital
652011-10-07 18:56:47.462197 I  DataDirect: sourceid 1 has lineup type: CableDigital
662011-10-07 18:56:59.253229 I  Grab complete.  Actual data from Sat Oct 8 04:00:00 2011 to Sun Oct 9 04:00:00 2011 (UTC)
672011-10-07 18:56:59.254336 I  Main temp tables populated.
682011-10-07 18:56:59.254347 I  Updating MythTV channels.
692011-10-07 18:56:59.291430 I  IconData: Updating icons for sourceid: 1
702011-10-07 18:56:59.291850 I  Channels updated.
712011-10-07 18:56:59.418138 I  Clearing data for source.
722011-10-07 18:56:59.418189 I  Clearing from Sat Oct 8 00:00:00 2011 to Sun Oct 9 00:00:00 2011 (localtime)
732011-10-07 18:57:00.122905 I  Data for source cleared.
742011-10-07 18:57:00.122915 I  Updating programs.
752011-10-07 18:57:00.998924 I  Program table update complete.
762011-10-07 18:57:00.998996 I  Checking day @ offset 2, date: Sun Oct 9 2011
772011-10-07 18:57:01.044069 N  Data is already present for Sun Oct 9 2011, skipping
782011-10-07 18:57:01.044113 I  Checking day @ offset 3, date: Mon Oct 10 2011
792011-10-07 18:57:01.087980 N  Data is already present for Mon Oct 10 2011, skipping
802011-10-07 18:57:01.088024 I  Checking day @ offset 4, date: Tue Oct 11 2011
812011-10-07 18:57:01.131324 N  Data is already present for Tue Oct 11 2011, skipping
822011-10-07 18:57:01.131367 I  Checking day @ offset 5, date: Wed Oct 12 2011
832011-10-07 18:57:01.174096 N  Data is already present for Wed Oct 12 2011, skipping
842011-10-07 18:57:01.174137 I  Checking day @ offset 6, date: Thu Oct 13 2011
852011-10-07 18:57:01.216710 N  Data is already present for Thu Oct 13 2011, skipping
862011-10-07 18:57:01.216754 I  Checking day @ offset 7, date: Fri Oct 14 2011
872011-10-07 18:57:01.259531 N  Data is already present for Fri Oct 14 2011, skipping
882011-10-07 18:57:01.259572 I  Checking day @ offset 8, date: Sat Oct 15 2011
892011-10-07 18:57:01.301720 N  Data is already present for Sat Oct 15 2011, skipping
902011-10-07 18:57:01.301782 I  Checking day @ offset 9, date: Sun Oct 16 2011
912011-10-07 18:57:01.343733 N  Data is already present for Sun Oct 16 2011, skipping
922011-10-07 18:57:01.343776 I  Checking day @ offset 10, date: Mon Oct 17 2011
932011-10-07 18:57:01.385315 N  Data is already present for Mon Oct 17 2011, skipping
942011-10-07 18:57:01.385358 I  Checking day @ offset 11, date: Tue Oct 18 2011
952011-10-07 18:57:01.426810 N  Data is already present for Tue Oct 18 2011, skipping
962011-10-07 18:57:01.426871 I  Checking day @ offset 12, date: Wed Oct 19 2011
972011-10-07 18:57:01.467987 N  Data is already present for Wed Oct 19 2011, skipping
982011-10-07 18:57:01.468029 I  Checking day @ offset 13, date: Thu Oct 20 2011
992011-10-07 18:57:01.508685 N  Data is already present for Thu Oct 20 2011, skipping
1002011-10-07 18:57:02.219633 I  Updating source #3 (zap1) with grabber schedulesdirect1
1012011-10-07 18:57:02.219995 I  Found 135 channels for source 3 which use grabber
1022011-10-07 18:57:02.220039 I  Checking day @ offset 0, date: Fri Oct 7 2011
1032011-10-07 18:57:02.349614 N  Data is already present for Fri Oct 7 2011, skipping
1042011-10-07 18:57:02.349659 I  Checking day @ offset 1, date: Sat Oct 8 2011
1052011-10-07 18:57:02.349665 I  Data Refresh always needed for tomorrow
1062011-10-07 18:57:02.349669 N  Refreshing data for Sat Oct 8 2011
1072011-10-07 18:57:02.349680 I  This DataDirect listings source is shared by 2 MythTV lineups
1082011-10-07 18:57:02.349685 N  We should use cached data for this one
1092011-10-07 18:57:02.350307 I  Retrieving datadirect data.
1102011-10-07 18:57:02.350330 I  Grabbing data for Fri Oct 7 2011 offset 1
1112011-10-07 18:57:02.350357 I  From Sat Oct 8 04:00:00 2011 to Sun Oct 9 04:00:00 2011 (UTC)
1122011-10-07 18:57:02.350368 I  DataDirect: Grabbing listing data
1132011-10-07 18:57:02.350439 I  DataDirect: Using DD cache
1142011-10-07 18:57:02.369770 I  DataDirect: Your subscription expires on Tue Jun 19 (2012) 10:33 PM
1152011-10-07 18:57:13.903914 I  Grab complete.  Actual data from Sat Oct 8 04:00:00 2011 to Sun Oct 9 04:00:00 2011 (UTC)
1162011-10-07 18:57:13.904840 I  Main temp tables populated.
1172011-10-07 18:57:13.904851 I  Updating MythTV channels.
1182011-10-07 18:57:13.921075 N  SourceUtil::IsProperlyConnected(): Connected to 0 analog, 0 digital and 0 virtual tuners
119                        Can not mix digital with other tuning information.
1202011-10-07 18:57:13.921099 N  SourceUtil::IsProperlyConnected(): Source ID 3 appears to be connected
121                        to 3 scanable inputs, and 1 non-scanable input. This may be a problem.
1222011-10-07 18:57:13.921114 I  IconData: Updating icons for sourceid: 3
1232011-10-07 18:57:13.921441 I  Channels updated.
1242011-10-07 18:57:14.147427 I  Clearing data for source.
1252011-10-07 18:57:14.147479 I  Clearing from Sat Oct 8 00:00:00 2011 to Sun Oct 9 00:00:00 2011 (localtime)
1262011-10-07 18:57:16.594574 I  Data for source cleared.
1272011-10-07 18:57:16.594585 I  Updating programs.
1282011-10-07 18:57:19.138628 I  Program table update complete.
1292011-10-07 18:57:19.138702 I  Checking day @ offset 2, date: Sun Oct 9 2011
1302011-10-07 18:57:19.278485 N  Data is already present for Sun Oct 9 2011, skipping
1312011-10-07 18:57:19.278532 I  Checking day @ offset 3, date: Mon Oct 10 2011
1322011-10-07 18:57:19.405871 N  Data is already present for Mon Oct 10 2011, skipping
1332011-10-07 18:57:19.405929 I  Checking day @ offset 4, date: Tue Oct 11 2011
1342011-10-07 18:57:19.530975 N  Data is already present for Tue Oct 11 2011, skipping
1352011-10-07 18:57:19.531024 I  Checking day @ offset 5, date: Wed Oct 12 2011
1362011-10-07 18:57:19.656385 N  Data is already present for Wed Oct 12 2011, skipping
1372011-10-07 18:57:19.656445 I  Checking day @ offset 6, date: Thu Oct 13 2011
1382011-10-07 18:57:19.780194 N  Data is already present for Thu Oct 13 2011, skipping
1392011-10-07 18:57:19.780242 I  Checking day @ offset 7, date: Fri Oct 14 2011
1402011-10-07 18:57:19.902427 N  Data is already present for Fri Oct 14 2011, skipping
1412011-10-07 18:57:19.902473 I  Checking day @ offset 8, date: Sat Oct 15 2011
1422011-10-07 18:57:20.023595 N  Data is already present for Sat Oct 15 2011, skipping
1432011-10-07 18:57:20.023640 I  Checking day @ offset 9, date: Sun Oct 16 2011
1442011-10-07 18:57:20.143977 N  Data is already present for Sun Oct 16 2011, skipping
1452011-10-07 18:57:20.144023 I  Checking day @ offset 10, date: Mon Oct 17 2011
1462011-10-07 18:57:20.263587 N  Data is already present for Mon Oct 17 2011, skipping
1472011-10-07 18:57:20.263633 I  Checking day @ offset 11, date: Tue Oct 18 2011
1482011-10-07 18:57:20.382754 N  Data is already present for Tue Oct 18 2011, skipping
1492011-10-07 18:57:20.382802 I  Checking day @ offset 12, date: Wed Oct 19 2011
1502011-10-07 18:57:20.501512 N  Data is already present for Wed Oct 19 2011, skipping
1512011-10-07 18:57:20.501559 I  Checking day @ offset 13, date: Thu Oct 20 2011
1522011-10-07 18:57:20.620040 N  Data is already present for Thu Oct 20 2011, skipping
1532011-10-07 18:57:21.140656 N  Data fetching complete.
1542011-10-07 18:57:21.140707 I  Adjusting program database end times.
1552011-10-07 18:57:22.617860 I      0 replacements made
1562011-10-07 18:57:22.617875 I  Marking generic episodes.
1572011-10-07 18:57:23.726699 I      Found 903
1582011-10-07 18:57:23.726771 I  Extending non-unique programids with multiple parts.
1592011-10-07 18:57:24.003428 I      MV003705470000 -> MV003705470201 (part 1 of 2)
1602011-10-07 18:57:24.004143 I      Found 2
1612011-10-07 18:57:24.004187 I  Marking repeats.
1622011-10-07 18:57:24.880222 I      Found 2151
1632011-10-07 18:57:24.880239 I  Unmarking new episode rebroadcast repeats.
1642011-10-07 18:57:25.687166 I      Found 0
1652011-10-07 18:57:28.279646 I  Marking episode first showings.
1662011-10-07 18:57:37.631523 I      Found 20084
1672011-10-07 18:57:37.631534 I  Marking episode last showings.
1682011-10-07 18:57:47.258984 I      Found 20084
1692011-10-07 18:57:47.285299 I  DataDirect: Grabbing next suggested grabbing time
1702011-10-07 18:57:47.782283 I  DataDirect: BlockedTime is: 2011-10-07T18:57:47
1712011-10-07 18:57:47.782731 I  DataDirect: NextSuggestedTime is: 2011-10-08T16:50:00
1722011-10-07 18:57:47.784499 I 
173===============================================================
174| Attempting to contact the master backend for rescheduling.  |
175| If the master is not running, rescheduling will happen when |
176| the master backend is restarted.                            |
177===============================================================
1782011-10-07 18:57:47.792319 I  MythCoreContext: Connecting to backend server: 192.168.10.10:6543 (try 1 of 1)
1792011-10-07 18:57:47.793771 I  Using protocol version 69
1802011-10-07 18:57:47.799051 N  mythfilldatabase run complete.
1812011-10-07 18:57:47.807495 I  Closing DB connection named 'DBManager2'
1822011-10-07 18:57:47.855528 I  Closing DB connection named 'DBManager1'
1832011-10-07 18:57:47.855617 I  Closing DB connection named 'DataDirectCon'
1842011-10-07 18:57:47.856146 I  DataDirect: Deleting temporary files