2012/03/09 21:34:15 >>> LOG START
2012/03/09 21:34:15 [protocols.external:3] Didn't find "ufetch".
2012/03/09 21:34:15 [protocols.external:3] Found "/usr/bin/wget".
2012/03/09 21:34:15 [main:3] Liquidsoap 1.0.0
2012/03/09 21:34:15 [main:3] Using: graphics=[distributed with Ocaml] pcre=6.0.1 dtools=0.2.2 duppy=0.4.2 duppy.syntax=0.4.2 cry=0.2.2 mm=0.2.0 ogg=0.4.3 vorbis=0.6.1 mad=0.4.4 flac=0.1.0 flac.ogg=0.1.0 dynlink=[distributed with Ocaml] lame=0.3.1 alsa=0.2.1 ao=0.2.0 taglib=0.2.0 camomile=0.7.1 portaudio=0.2.0 pulseaudio=0.1.2
2012/03/09 21:34:15 [dynamic.loader:2] Could not load plugins in directory /usr/local/lib/liquidsoap/1.0.0/plugins.
2012/03/09 21:34:15 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2012/03/09 21:34:15 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2012/03/09 21:34:15 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2012/03/09 21:34:15 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2012/03/09 21:34:15 [threads:3] Created thread "generic queue #1".
2012/03/09 21:34:15 [threads:3] Created thread "generic queue #2".
2012/03/09 21:34:15 [threads:3] Created thread "non-blocking queue #1".
2012/03/09 21:34:15 [twrradio(dot)ogg:3] Connecting mount twrradio.ogg for source@radio.twr.org...
2012/03/09 21:34:19 [server:3] New client: localhost.
2012/03/09 21:34:19 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/7989ce34b42e33c8efebf3b7d2887cda.mp3".
2012/03/09 21:34:19 [server:3] Client localhost disconnected.
2012/03/09 21:34:20 [twrradio(dot)ogg:3] Connection setup was successful.
2012/03/09 21:34:21 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --connect --stream-id=1 --time=1331346855.78
2012/03/09 21:34:21 [twrradio(dot)mp3:3] Connecting mount twrradio.mp3 for source@radio.twr.org...
2012/03/09 21:34:26 [twrradio(dot)mp3:3] Connection setup was successful.
2012/03/09 21:34:26 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --connect --stream-id=2 --time=1331346855.78
2012/03/09 21:34:26 [threads:3] Created thread "wallclock_main" (1 total).
2012/03/09 21:34:26 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2012/03/09 21:34:26 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/7989ce34b42e33c8efebf3b7d2887cda.mp3" (RID 0).
2012/03/09 21:34:26 [fallback_5163:3] Switch to cue_cut_5076.
2012/03/09 21:34:26 [cue_cut_5076:3] Cueing in...
2012/03/09 21:34:26 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='697' --media-id=9442
2012/03/09 21:34:26 [lang:3] Using stream_format 0
2012/03/09 21:34:31 [clock.wallclock_main:2] We must catchup 5.57 seconds!
2012/03/09 21:48:52 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/daedbc1fb9365be97c8f090e5ae489d6.mp3".
2012/03/09 21:48:52 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/7989ce34b42e33c8efebf3b7d2887cda.mp3".
2012/03/09 21:48:52 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 21:48:52 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/daedbc1fb9365be97c8f090e5ae489d6.mp3" (RID 1).
2012/03/09 21:48:52 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 21:48:52 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='697' --media-id=9443
2012/03/09 21:48:53 [lang:3] Using stream_format 0
2012/03/09 21:48:58 [clock.wallclock_main:2] We must catchup 5.46 seconds!
2012/03/09 21:53:06 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/0a2d9626fd683150b8d08c448d22eef7.mp3".
2012/03/09 21:53:07 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/daedbc1fb9365be97c8f090e5ae489d6.mp3".
2012/03/09 21:53:07 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 21:53:07 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/0a2d9626fd683150b8d08c448d22eef7.mp3" (RID 2).
2012/03/09 21:53:07 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 21:53:07 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='697' --media-id=9444
2012/03/09 21:53:07 [lang:3] Using stream_format 0
2012/03/09 21:53:12 [clock.wallclock_main:2] We must catchup 5.38 seconds!
2012/03/09 21:56:32 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/9956c9eae9351527e5a6e7e24334ec9a.mp3".
2012/03/09 21:56:32 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/0a2d9626fd683150b8d08c448d22eef7.mp3".
2012/03/09 21:56:32 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 21:56:32 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/9956c9eae9351527e5a6e7e24334ec9a.mp3" (RID 3).
2012/03/09 21:56:32 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 21:56:32 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='697' --media-id=9445
2012/03/09 21:56:33 [lang:3] Using stream_format 0
2012/03/09 21:56:38 [clock.wallclock_main:2] We must catchup 5.34 seconds!
2012/03/09 22:00:34 [server:3] New client: localhost.
2012/03/09 22:00:34 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-02-30-22/9956c9eae9351527e5a6e7e24334ec9a.mp3".
2012/03/09 22:00:34 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/317cd35e5b84be3875c78d2fb85b170f.mp3".
2012/03/09 22:00:34 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:34 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/317cd35e5b84be3875c78d2fb85b170f.mp3" (RID 0).
2012/03/09 22:00:34 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/317cd35e5b84be3875c78d2fb85b170f.mp3".
2012/03/09 22:00:34 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:34 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:34 [fallback_5163:3] Switch to src_5161 with forgetful transition.
2012/03/09 22:00:34 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9446
2012/03/09 22:00:34 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/1f0093642441bb61031647d4c2a0d5a2.mp3".
2012/03/09 22:00:34 [server:3] Client localhost disconnected.
2012/03/09 22:00:34 [lang:3] Using stream_format 0
2012/03/09 22:00:34 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/1f0093642441bb61031647d4c2a0d5a2.mp3" (RID 4).
2012/03/09 22:00:34 [fallback_5163:3] Switch to cue_cut_5076 with transition.
2012/03/09 22:00:34 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9446
2012/03/09 22:00:34 [lang:3] Using stream_format 0
2012/03/09 22:00:39 [clock.wallclock_main:2] We must catchup 5.33 seconds!
2012/03/09 22:00:39 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/1f0093642441bb61031647d4c2a0d5a2.mp3".
2012/03/09 22:00:39 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:39 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/ad927c5813b4a68d2964e80cb4152832.mp3".
2012/03/09 22:00:39 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:39 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/ad927c5813b4a68d2964e80cb4152832.mp3" (RID 5).
2012/03/09 22:00:39 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9447
2012/03/09 22:00:39 [lang:3] Using stream_format 0
2012/03/09 22:00:39 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/ad927c5813b4a68d2964e80cb4152832.mp3".
2012/03/09 22:00:39 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:39 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/18415f3683fc7730d772dc5f3c6b012d.mp3".
2012/03/09 22:00:39 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:39 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/18415f3683fc7730d772dc5f3c6b012d.mp3" (RID 6).
2012/03/09 22:00:39 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9448
2012/03/09 22:00:39 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9447
2012/03/09 22:00:39 [lang:3] Using stream_format 0
2012/03/09 22:00:39 [lang:3] Using stream_format 0
2012/03/09 22:00:39 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/18415f3683fc7730d772dc5f3c6b012d.mp3".
2012/03/09 22:00:39 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:39 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:39 [fallback_5163:3] Switch to src_5161 with forgetful transition.
2012/03/09 22:00:39 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9449
2012/03/09 22:00:39 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/c61e31ff649655315e6310a0fa9a3543.mp3".
2012/03/09 22:00:40 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9448
2012/03/09 22:00:40 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9447
2012/03/09 22:00:40 [lang:3] Using stream_format 0
2012/03/09 22:00:40 [lang:3] Using stream_format 0
2012/03/09 22:00:40 [lang:3] Using stream_format 0
2012/03/09 22:00:40 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/c61e31ff649655315e6310a0fa9a3543.mp3" (RID 7).
2012/03/09 22:00:40 [fallback_5163:3] Switch to cue_cut_5076 with transition.
2012/03/09 22:00:40 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9449
2012/03/09 22:00:40 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9448
2012/03/09 22:00:40 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9447
2012/03/09 22:00:40 [lang:3] Using stream_format 0
2012/03/09 22:00:40 [lang:3] Using stream_format 0
2012/03/09 22:00:40 [lang:3] Using stream_format 0
2012/03/09 22:00:45 [clock.wallclock_main:2] We must catchup 11.84 seconds!
2012/03/09 22:00:45 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/c61e31ff649655315e6310a0fa9a3543.mp3".
2012/03/09 22:00:45 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:45 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/d7c9b0740db7235d5606fda913d3f741.mp3".
2012/03/09 22:00:45 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:45 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/d7c9b0740db7235d5606fda913d3f741.mp3" (RID 8).
2012/03/09 22:00:45 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9450
2012/03/09 22:00:46 [lang:3] Using stream_format 0
2012/03/09 22:00:46 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/d7c9b0740db7235d5606fda913d3f741.mp3".
2012/03/09 22:00:46 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:46 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:46 [fallback_5163:3] Switch to src_5161 with forgetful transition.
2012/03/09 22:00:46 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9451
2012/03/09 22:00:46 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/fce6c22a29a0846171d4aa6fd674379e.mp3".
2012/03/09 22:00:46 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9450
2012/03/09 22:00:46 [lang:3] Using stream_format 0
2012/03/09 22:00:46 [lang:3] Using stream_format 0
2012/03/09 22:00:46 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/fce6c22a29a0846171d4aa6fd674379e.mp3" (RID 9).
2012/03/09 22:00:46 [fallback_5163:3] Switch to cue_cut_5076 with transition.
2012/03/09 22:00:46 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9451
2012/03/09 22:00:46 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9450
2012/03/09 22:00:46 [lang:3] Using stream_format 0
2012/03/09 22:00:46 [lang:3] Using stream_format 0
2012/03/09 22:00:51 [clock.wallclock_main:2] We must catchup 17.64 seconds!
2012/03/09 22:00:51 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/fce6c22a29a0846171d4aa6fd674379e.mp3".
2012/03/09 22:00:51 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:51 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/599ad0b4f88a16264288bdf4041ad3cd.mp3".
2012/03/09 22:00:51 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:51 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/599ad0b4f88a16264288bdf4041ad3cd.mp3" (RID 10).
2012/03/09 22:00:51 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9452
2012/03/09 22:00:51 [lang:3] Using stream_format 0
2012/03/09 22:00:51 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/599ad0b4f88a16264288bdf4041ad3cd.mp3".
2012/03/09 22:00:51 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:51 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:51 [fallback_5163:3] Switch to src_5161 with forgetful transition.
2012/03/09 22:00:51 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9453
2012/03/09 22:00:51 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/773bdb7e04a588a6407a28dda8bfc682.mp3".
2012/03/09 22:00:52 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9452
2012/03/09 22:00:52 [lang:3] Using stream_format 0
2012/03/09 22:00:52 [lang:3] Using stream_format 0
2012/03/09 22:00:52 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/773bdb7e04a588a6407a28dda8bfc682.mp3" (RID 11).
2012/03/09 22:00:52 [fallback_5163:3] Switch to cue_cut_5076 with transition.
2012/03/09 22:00:52 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9453
2012/03/09 22:00:52 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9452
2012/03/09 22:00:52 [lang:3] Using stream_format 0
2012/03/09 22:00:52 [lang:3] Using stream_format 0
2012/03/09 22:00:52 [twrradio(dot)ogg:2] Error while sending data: could not write data to host: Broken pipe in write()!
2012/03/09 22:00:52 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --error='could not write data to host: Broken pipe in write()' --stream-id=1 --time=1331346855.78
2012/03/09 22:00:52 [twrradio(dot)ogg:3] Closing connection...
2012/03/09 22:00:52 [twrradio(dot)ogg:3] Will try to reconnect in 5.00 seconds.
2012/03/09 22:00:57 [clock.wallclock_main:2] We must catchup 23.57 seconds!
2012/03/09 22:00:57 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/773bdb7e04a588a6407a28dda8bfc682.mp3".
2012/03/09 22:00:57 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:00:57 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:00:57 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/e8a1c37fc7fccbaa101b0ee1710d3407.mp3".
2012/03/09 22:00:57 [fallback_5163:3] Switch to src_5161 with forgetful transition.
2012/03/09 22:00:57 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9454
2012/03/09 22:00:57 [lang:3] Using stream_format 0
2012/03/09 22:00:57 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/e8a1c37fc7fccbaa101b0ee1710d3407.mp3" (RID 12).
2012/03/09 22:00:57 [fallback_5163:3] Switch to cue_cut_5076 with transition.
2012/03/09 22:00:57 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9454
2012/03/09 22:00:58 [lang:3] Using stream_format 0
2012/03/09 22:01:03 [twrradio(dot)ogg:3] Connecting mount twrradio.ogg for source@radio.twr.org...
2012/03/09 22:01:08 [twrradio(dot)ogg:3] Connection setup was successful.
2012/03/09 22:01:08 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --connect --stream-id=1 --time=1331346855.78
2012/03/09 22:01:08 [clock.wallclock_main:2] We must catchup 34.27 seconds!
2012/03/09 22:01:08 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/2012-03-10-03-00-34/e8a1c37fc7fccbaa101b0ee1710d3407.mp3".
2012/03/09 22:01:08 [cue_cut_5076:2] Ignoring negative cue-in point.
2012/03/09 22:01:08 [cue_cut_5076:3] End of track before cue-out point.
2012/03/09 22:01:08 [fallback_5163:3] Switch to src_5161 with forgetful transition.
2012/03/09 22:01:08 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9455
2012/03/09 22:01:08 [lang:3] Using stream_format 0
2012/03/09 22:01:08 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='698' --media-id=9455
2012/03/09 22:01:08 [lang:3] Using stream_format 0
2012/03/09 22:01:13 [clock.wallclock_main:2] We must catchup 39.69 seconds!
2012/03/09 22:01:19 [clock.wallclock_main:2] We must catchup 44.89 seconds!
2012/03/09 22:01:20 [clock.wallclock_main:2] We must catchup 35.97 seconds (we've been late for 100 rounds)!
2012/03/09 22:01:21 [clock.wallclock_main:2] We must catchup 27.33 seconds (we've been late for 100 rounds)!
2012/03/09 22:01:22 [clock.wallclock_main:2] We must catchup 19.41 seconds (we've been late for 100 rounds)!
2012/03/09 22:01:23 [clock.wallclock_main:2] We must catchup 10.90 seconds (we've been late for 100 rounds)!
2012/03/09 22:01:24 [clock.wallclock_main:2] We must catchup 1.94 seconds (we've been late for 100 rounds)!

From Pypo:

2012-03-09 21:56:32,950 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 21:56:32,950 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 21:56:32,950 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 21:56:32,950 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 697
2012-03-09 21:56:32,950 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9445/schedule_id/697
2012-03-09 21:56:33,025 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 21:56:33,026 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 21:56:33,026 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 21:56:42,422 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 21:57:12,452 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 21:57:42,482 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 21:58:12,512 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 21:58:42,542 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 21:59:12,572 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 21:59:42,602 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:00:12,632 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:00:26,646 DEBUG - [pypopush.py : push() : line 87] - Preparing to push playlist scheduled at: 2012-03-10-03-00-34
2012-03-09 22:00:26,646 DEBUG - [pypopush.py : push_liquidsoap() : line 145] - Epoch start: 1331348434
2012-03-09 22:00:26,646 DEBUG - [pypopush.py : push_liquidsoap() : line 146] - Epoch now: 1331348426.65
2012-03-09 22:00:26,647 DEBUG - [pypopush.py : push_liquidsoap() : line 153] - sleeping for 7.35315108299 s
2012-03-09 22:00:34,007 DEBUG - [pypopush.py : push_liquidsoap() : line 159] - source.skip

2012-03-09 22:00:34,007 DEBUG - [pypopush.py : push_liquidsoap() : line 166] - vars.pypo_data 698

2012-03-09 22:00:34,007 DEBUG - [pypopush.py : push_liquidsoap() : line 169] - Preparing to push playlist 2012-03-10-03-00-34
2012-03-09 22:00:34,104 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:34,104 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:34,104 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:34,104 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:34,104 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9446/schedule_id/698
2012-03-09 22:00:34,178 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:34,179 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:34,179 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:34,185 DEBUG - [pypopush.py : push_liquidsoap() : line 178] - Skipped
END
Done
END
0
END
Evening
END
4
END
Evening
END
5
END
Evening
END
6
END
Evening
END
7
END
Evening
END
8
END
Evening
END
9
END
Evening
END
10
END
Evening
END
11
END
Evening
END
12
END
Evening
END
Bye!

2012-03-09 22:00:34,185 DEBUG - [pypopush.py : push() : line 94] - Pushed to liquidsoap, updating 'played' status.
2012-03-09 22:00:34,185 DEBUG - [pypopush.py : push() : line 100] - Doing callback to server to update 'played' status.
2012-03-09 22:00:34,185 DEBUG - [api_client.py : notify_scheduled_item_start_playing() : line 298] - http://localhost:80/api/notify-schedule-group-play/api_key/%%api_key%%/schedule_id/698
2012-03-09 22:00:34,248 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:34,248 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:34,248 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:34,248 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:34,248 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9446/schedule_id/698
2012-03-09 22:00:34,263 INFO - [api_client.py : notify_scheduled_item_start_playing() : line 304] - API-Status 1
2012-03-09 22:00:34,263 INFO - [api_client.py : notify_scheduled_item_start_playing() : line 305] - API-Message
2012-03-09 22:00:34,322 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:34,322 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:34,322 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:39,469 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:39,469 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:39,469 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:39,469 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:39,469 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9447/schedule_id/698
2012-03-09 22:00:39,542 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:39,542 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:39,542 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:39,607 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:39,607 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:39,607 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:39,607 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:39,608 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9448/schedule_id/698
2012-03-09 22:00:39,749 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:39,749 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:39,750 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:39,810 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:39,810 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:39,810 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:39,811 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:39,811 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9447/schedule_id/698
2012-03-09 22:00:39,883 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:39,883 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:39,883 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:39,943 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:39,944 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:39,944 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:39,944 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:39,944 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9449/schedule_id/698
2012-03-09 22:00:40,017 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:40,017 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:40,017 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:40,078 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:40,078 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:40,078 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:40,079 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:40,079 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9448/schedule_id/698
2012-03-09 22:00:40,152 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:40,152 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:40,152 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:40,214 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:40,214 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:40,214 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:40,214 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:40,215 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9447/schedule_id/698
2012-03-09 22:00:40,288 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:40,288 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:40,288 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:40,349 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:40,349 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:40,349 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:40,349 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:40,349 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9449/schedule_id/698
2012-03-09 22:00:40,422 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:40,422 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:40,422 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:40,483 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:40,483 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:40,484 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:40,484 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:40,484 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9448/schedule_id/698
2012-03-09 22:00:40,564 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:40,564 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:40,564 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:40,624 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:40,624 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:40,625 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:40,625 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:40,625 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9447/schedule_id/698
2012-03-09 22:00:40,698 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:40,698 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:40,698 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:46,029 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:46,029 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:46,029 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:46,030 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:46,030 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9450/schedule_id/698
2012-03-09 22:00:46,124 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:46,124 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:46,124 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:46,193 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:46,193 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:50,279 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:00:51,866 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:51,866 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:51,866 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:51,866 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:51,866 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9452/schedule_id/698
2012-03-09 22:00:51,940 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:51,940 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:51,940 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:52,010 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:52,011 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:52,011 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:52,011 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:52,011 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9453/schedule_id/698
2012-03-09 22:00:52,096 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:52,097 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:52,097 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:52,161 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:52,161 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:52,161 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:52,161 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:52,161 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9452/schedule_id/698
2012-03-09 22:00:52,235 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:52,235 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:52,235 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:52,296 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:52,296 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:52,297 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:52,297 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:52,297 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9453/schedule_id/698
2012-03-09 22:00:52,373 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:52,373 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:52,373 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:52,434 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:52,435 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:52,435 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:52,435 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:52,435 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9452/schedule_id/698
2012-03-09 22:00:52,506 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:52,506 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:52,507 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:52,600 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 88] - #################################################
2012-03-09 22:00:52,600 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 89] - # Calling server to update liquidsoap status    #
2012-03-09 22:00:52,601 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 90] - #################################################
2012-03-09 22:00:52,601 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 91] - msg = could not write data to host: Broken pipe in write()
2012-03-09 22:00:52,601 DEBUG - [api_client.py : notify_liquidsoap_status() : line 590] - http://localhost:80/api/update-liquidsoap-status/format/json/api_key/NYRO6HF0W2SX1752EW08/msg/could%20not%20write%20data%20to%20host%3A%20Broken%20pipe%20in%20write%28%29/stream_id/1/boot_time/1331346855.78
2012-03-09 22:00:52,672 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 93] - Response: null
2012-03-09 22:00:57,843 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:57,843 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:57,843 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:57,843 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:57,844 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9454/schedule_id/698
2012-03-09 22:00:57,923 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:57,923 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:57,923 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:00:57,996 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:00:57,996 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:00:57,996 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:00:57,996 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:00:57,996 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9454/schedule_id/698
2012-03-09 22:00:58,067 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:00:58,068 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:00:58,068 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:01:08,426 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 88] - #################################################
2012-03-09 22:01:08,426 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 89] - # Calling server to update liquidsoap status    #
2012-03-09 22:01:08,426 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 90] - #################################################
2012-03-09 22:01:08,426 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 91] - msg = OK
2012-03-09 22:01:08,427 DEBUG - [api_client.py : notify_liquidsoap_status() : line 590] - http://localhost:80/api/update-liquidsoap-status/format/json/api_key/NYRO6HF0W2SX1752EW08/msg/OK/stream_id/1/boot_time/1331346855.78
2012-03-09 22:01:08,498 DEBUG - [pypo-notify.py : notify_liquidsoap_status() : line 93] - Response: null
2012-03-09 22:01:08,561 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:01:08,561 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:01:08,561 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:01:08,561 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:01:08,561 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9455/schedule_id/698
2012-03-09 22:01:08,631 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:01:08,631 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:01:08,631 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:01:08,690 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################
2012-03-09 22:01:08,690 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - # Calling server to update about what's playing #
2012-03-09 22:01:08,690 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 79] - #################################################
2012-03-09 22:01:08,690 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - data = 698
2012-03-09 22:01:08,690 DEBUG - [api_client.py : notify_media_item_start_playing() : line 326] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/9455/schedule_id/698
2012-03-09 22:01:08,760 INFO - [api_client.py : notify_media_item_start_playing() : line 330] - API-Status 1
2012-03-09 22:01:08,760 INFO - [api_client.py : notify_media_item_start_playing() : line 331] - API-Message
2012-03-09 22:01:08,760 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
2012-03-09 22:01:20,309 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:01:50,339 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:02:20,369 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:02:50,399 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:03:20,429 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:03:50,459 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:04:20,489 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:04:50,519 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:05:20,549 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:05:50,579 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:06:20,610 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:06:50,640 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:07:20,670 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:07:50,700 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:08:20,730 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:08:50,760 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:09:20,790 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:09:50,820 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:10:20,850 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:10:50,880 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:11:20,910 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:11:50,942 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:12:20,972 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:12:51,002 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:13:21,032 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:13:51,062 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:14:21,092 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:14:51,122 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:15:21,152 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:15:51,182 INFO - [pypopush.py : run() : line 193] - heartbeat
2012-03-09 22:16:21,212 INFO - [pypopush.py : run() : line 193] - heartbeat