Rick's b.log - entry 2023/02/18

Denver IR-135 serial data

I dragged some of the cut branches from the old willow tree down to the wood graveyard, and Anna was out. I had to give up on things because Anna climbed an oak, jumped across to the barn roof, and then wandered all over because there was no obvious way down.
I put up a ladder, but it took a lot of coaxing before she decided to use it.

The grass wasn't tall enough to necessitate a mow if it wasn't favourable conditions, so I left it. Came inside and fiddled with the internet radio instead.

This time I took it apart completely. Here's the back of the main board.

Internet radio main board.

I've already described this, so a quick recap. Weird metal thing at the top is the WiFi/Bluetooth antenna. Below that, an ESP32 microcontroller. Below that, to the left, PSRAM and to the right, Flash. Carrying on down, an audio driver chip that translates I2S to audio signals. Over on the lower right an amplifier chip for the speaker, and going up (by the two white sockets) the LiPo charger chip.

On the other side, eight buttons. One rotary button. An IR receiver. And a socket that a ribbon cable for the LCD module plugs into. Here's a quick photo of the other side, but it's not particularly interesting.

Internet radio main board - front.

Notice the band of foam insulation around the board, to seal it tightly to the front panel to avoid rattling. That's also the reason for the foam pads between the button faces and the buttons themselves.

I used my oscilloscope to probe the four pin terminal that I thought was a serial port. It was, and my pin assignments were exactly correct.

I wanted to install a header there to plug into, but I've lost the components. It was a tiny bag of header strips (three?) in a big flat Amazon envelope. I suspect I may have tossed the envelope without realising the stuff was still inside. Yeah, I know...

So I did a quick DIY job with my soldering iron and sewing pins. So these pins are literally pins. ☺

Serial pins.

It looks a bit of a hack, and it clearly is. However it was possible to solder these in place from the component side of the board. If I was doing a proper solder job with a header block, I'd have to take the LCD assembly apart, and it looks fragile. So best to just leave it in place.

The left pin is ground. The next terminal is +3.3V but it's not necessary for a functional serial port so I left it empty. The second pin (or third terminal) is Tx from the ESP32, and the one on the right is Rx to the ESP32.

I hooked host Rx to ESP32 Tx (yellow) and the ground (brown) to a dinky little USB serial adaptor. Then spent a while tracking down what it was in order to find a driver for it. The textual identity "USB2.0 Ser!" wasn't much help, but the manufacturer (&1A86) and device ID (&7523) helped me find out that it was a CH340 serial convertor from QinHeng electronics (or a passable clone of it) to locate information and a Windows driver.

Then, I connected just the battery to the radio and pressed the power button.

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:4516
load:0x40078000,len:11260
load:0x40080400,len:5952
entry 0x400806a0

Then the device ceased responding.

Oh, okay, I remember. I have to hold the power button down a bit.

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:4516
load:0x40078000,len:11260
load:0x40080400,len:5952
entry 0x400806a0
I (948) psram: This chip is ESP32-D0WD
I (958) psram: PSRAM is in 2T mode
I (959) spiram: Found 32MBit SPI RAM device
I (959) spiram: SPI RAM mode: flash 80m sram 80m
I (961) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (969) cpu_start: cpu freq: 240
I (973) cpu_start: Pro cpu up.
I (976) cpu_start: Application information:
I (981) cpu_start: Project name:     IR-135
I (986) cpu_start: ELF file SHA256:  3c935f1346673730...
I (992) cpu_start: ESP-IDF:          v3.3.5-dirty
I (997) cpu_start: Starting app cpu, entry point is 0x400818f8
I (0) cpu_start: App cpu up.

And then the device ceased responding.

Oh, FFS. Have to hold the power button down for a long time!

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:4516
load:0x40078000,len:11260
load:0x40080400,len:5952
entry 0x400806a0
I (948) psram: This chip is ESP32-D0WD
I (958) psram: PSRAM is in 2T mode
I (959) spiram: Found 32MBit SPI RAM device
I (959) spiram: SPI RAM mode: flash 80m sram 80m
I (961) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (969) cpu_start: cpu freq: 240
I (973) cpu_start: Pro cpu up.
I (976) cpu_start: Application information:
I (981) cpu_start: Project name:     IR-135
I (986) cpu_start: ELF file SHA256:  3c935f1346673730...
I (992) cpu_start: ESP-IDF:          v3.3.5-dirty
I (997) cpu_start: Starting app cpu, entry point is 0x400818f8
I (0) cpu_start: App cpu up.
I (1485) spiram: SPI SRAM memory test OK
I (1535) heap_init: Initializing. RAM available for dynamic allocation:
I (1535) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1537) heap_init: At 3FFB7468 len 00000B98 (2 KiB): DRAM
I (1543) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1549) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (1555) heap_init: At 3FFCC2D8 len 00013D28 (79 KiB): DRAM
I (1562) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1568) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1575) heap_init: At 4009E660 len 000019A0 (6 KiB): IRAM
I (1581) cpu_start: Pro cpu start user code
I (1586) spiram: Adding pool of 3431K of external SPI memory to heap allocator
I (40) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starti.

By now, the bootloader has started the system up and is ready to hand over to the system firmware. It was interesting that there was more output beyond the standard bootloader messages.......but not as interesting as what was to come.

Oh, and if you're wondering about the colours in the following dumps, the data output to the serial port includes ANSI style control codes for changing colour, namely <esc>[0;32m at the start of most lines (to set green text), and <esc>[0m at the end of those lines (to return to normal white text).
Some lines are in yellow (colour 33) and errors in red (colour 31).

Anyway, let's carry on. The radio pretty much offers a running narration of what it does. Which is interesting/amusing/mindblowing (delete as applicable).

The LCD backlight is turned on in the second line below. This is when it's possible to let go of the power button and the device will stay on.
Note that the timestamps begin now, but it's about two seconds more for the above stuff to happen.

0:00:00.340 I (340) reportSystem: IR-135 20211110.1013, Running partition type 0 subtype 16 (offset 0x00020000)
 0:00:01.436 I (1436) setBacklight: 60%
0:00:01.437 I (1437) I2S: DMA Malloc info, datalen=blocksize=4088, dma_buf_count=4
0:00:01.441 I (1441) I2S: APLL: Req RATE: 48000, real rate: 47999.961, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 12287990.000, SCLK: 1535998.750000, diva: 1, divb: 0

----------------------------- ESP Audio Platform -----------------------------
|                                                                            |
|                             Player_Version 0.97                            |
|                     Compile date: Apr 19 2021-11:28:06                     |
------------------------------------------------------------------------------
0:00:01.508 I (1508) BROADCAST: func:BroadcastInit, list=0x3ffd4fa0, que=0x0
0:00:01.509 I (1509) I2S_READER: CreateI2sStreamReader
0:00:01.511 I (1511) I2S_WRITER: CreateI2sStreamWriter
0:00:01.517 W (1517) SOFT_CODEC: CodecStop, have no codec instance,0x0
0:00:01.524 W (1524) SOFT_CODEC: CodecStop, have no codec instance,0x0
0:00:01.531 I (1531) MEDIA_CTRL: Media started, and wait, ctrl addr=3f8a6ab8
0:00:01.918 I (1918) READER: tskRead, waiting for a START_PLAY
0:00:01.920 I (1920) WebServer: SetCurrentIp ------> 127.0.0.1
0:00:01.924 I (1924) wifi:0:00:01.924 wifi driver task: 3ffde104, prio:23, stack:3072, core=00:00:01.924 
0:00:01.930 I (1930) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
0:00:01.941 I (1941) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
0:00:01.967 I (1967) wifi:0:00:01.967 wifi firmware version: dc300370:00:01.967 
0:00:01.967 I (1967) wifi:0:00:01.967 config NVS flash: enabled0:00:01.967 
0:00:01.970 I (1970) wifi:0:00:01.970 config nano formating: enabled0:00:01.970 
0:00:01.977 I (1977) wifi:0:00:01.978 Init data frame dynamic rx buffer num: 320:00:01.978 
0:00:01.985 I (1985) wifi:0:00:01.985 Init management frame dynamic rx buffer num: 320:00:01.985 
0:00:01.994 I (1994) wifi:0:00:01.994 Init management short buffer num: 320:00:01.994 
0:00:02.001 I (2001) wifi:0:00:02.001 Init static tx buffer num: 240:00:02.001 
0:00:02.009 I (2009) wifi:0:00:02.010 Init static rx buffer size: 22120:00:02.010 
0:00:02.016 I (2016) wifi:0:00:02.016 Init static rx buffer num: 80:00:02.016 
0:00:02.023 I (2023) wifi:0:00:02.023 Init dynamic rx buffer num: 320:00:02.023 
0:00:02.030 I (2030) wifi_init: rx ba win: 16
0:00:02.035 I (2035) wifi_init: tcpip mbox: 48
0:00:02.040 I (2040) wifi_init: udp mbox: 6
0:00:02.045 I (2045) wifi_init: tcp mbox: 46
0:00:02.050 I (2050) wifi_init: tcp tx win: 5840
0:00:02.055 I (2055) wifi_init: tcp rx win: 65535
0:00:02.060 I (2060) wifi_init: tcp mss: 1460
0:00:02.065 I (2065) wifi_init: LWIP IRAM OP enabled
0:00:02.071 I (2071) phy_init: phy_version 4660,0162888,Dec 23 2020
0:00:02.171 I (2171) wifi:0:00:02.171 mode : sta (78:21:84:xx:xx:xx)0:00:02.171 
0:00:02.173 I (2173) wifi:0:00:02.173 set country: cc=EU. schan=1 nchan=14 policy=0
0:00:02.174 
0:00:02.177 I (2177) wifi:0:00:02.177 Set ps type: 0
0:00:02.180 
0:00:02.184 I (2184) startKeyboard: type = 0, gradient = 53470, offset = 142, vref = 1114
0:00:02.186 I (2186) wifi:0:00:02.190 new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:10:00:02.191 
0:00:02.200 I (2200) wifi:0:00:02.200 state: init -> auth (b0)0:00:02.200 
0:00:02.208 I (2208) startKeyboard: type = 0, gradient = 15619, offset = 75, vref = 1114
0:00:02.210 I (2210) wifi:0:00:02.215 state: auth -> assoc (0)0:00:02.215 
0:00:02.226 I (2226) wifi:0:00:02.227 state: assoc -> run (10)0:00:02.227 
0:00:02.230 I (2230) configEqMode: EQ mode = 1
0:00:02.239 I (2239) setBacklight: 800px
0:00:02.242 I (2242) setResumeLastPlayTimer: Resume play after 3 seconds

By this point, the system was up and functional. The next task is to connect to a WiFi network.

0:00:02.457 I (2457) wifi:0:00:02.457 connected with VonetsRepeater, aid = 3, channel 1, BW20, bssid = 00:17:13:1c:xx:xxx:xx:xx.457 
0:00:02.458 I (2458) wifi:0:00:02.458 security type: 3, phy: bgn, rssi: -190:00:02.458 
0:00:02.471 I (2471) wifi:0:00:02.472 pm start, type: 0
0:00:02.472 
0:00:02.473 I (2473) NETWORK: SYSTEM_EVENT_STA_CONNECTED
0:00:02.497 I (2497) wifi:0:00:02.498 AP's beacon interval = 102400 us, DTIM period = 10:00:02.498 
0:00:03.586 I (3585) event: sta ip: 192.168.1.12, mask: 255.255.255.0, gw: 192.168.1.1
0:00:03.586 I (3586) NETWORK: SYSTEM_EVENT_STA_GOTIP
0:00:03.589 I (3589) NETWORK: NONE --> STA
0:00:03.595 I (3595) SKYTUNE: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_GOT_IP
0:00:03.602 I (3602) READER: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_GOT_IP
0:00:03.609 I (3609) UPNP: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_GOT_IP
0:00:03.617 I (3617) WebServer: webServerEventNotify, DEVICE_NOTIFY_NETWORK_GOT_IP
0:00:03.626 I (3626) WebServer: SetCurrentIp ------> 192.168.1.12
0:00:03.632 I (3632) UI: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_GOT_IP

This is now about three and a half seconds into the startup, plus two seconds for the bootloader start. So we're connected after about five and a half seconds.

So we're online, time to get the time, ping the mothership, and see if there's a station to resume playing.

0:00:03.640 I (3640) NETWORK: getNetworkTime, ENTER
0:00:03.920 I (3920) SKYTUNE: Connecting to Skytune server... 0
0:00:04.163 I (4163) SKYTUNE: Skytune Server connected, 80
0:00:04.707 I (4707) UI: bgTask, try to resume last song
0:00:04.708 I (4708) PLAYER: playSource, ENTER, myFav,12,14,"/spiffs/myFav.txt","BBC Radio 4 FM","1"
0:00:04.712 I (4712) setRampVolume: Target volume = 20, rate = 1
0:00:04.722 I (4722) PLAYER: playerPrepareNext, Enter, srcRef = myFav,12,14,"/spiffs/myFav.txt","BBC Radio 4 FM","1", stopCode = 0, desirePos = 0, numOfErr = 0

Now we have a station to play, the radio goes through the process of changing station. This involves stopping the currently playing station, but this won't have any effect as there's nothing currently playing.
Somewhere along the way, we've requested the stream URL from SkyTune, so we can connect to it.

You'll notice, also, that we're connecting to SkyTune to check for firmware updates in the background and to see if the radio station data is up to date.

0:00:04.842 I (4842) PLAYER: stopPlay, ENTER
0:00:04.842 I (4842) PLAYER: stopPlay, LEAVE
0:00:04.843 I (4843) READER: setPlayerState, STOPPED -> CONNECTING_TO_NETWORK, stopCode = 0
0:00:04.845 I (4845) PLAYER: playerPrepareNext, Leave
0:00:04.850 I (4850) READER: setPlayerState, CONNECTING_TO_NETWORK -> CONNECTING_TO_SERVER, stopCode = 0
0:00:04.866 I (4866) ec_handle_https_url: Playing: http://open.live.bbc.co.uk/mediaselector/6/redir/version/20/mediaset/audio-syndication-vlow/proto/http/transferformat/hls/vpid/bbc_radio_fourfm
0:00:04.867 I (4867) SKYTUNE: Send logon message to server
0:00:05.045 I (5045) HTTP_REQ: Code: 302
0:00:05.067 I (5067) ec_req_perform: Starting again (B)!
0:00:05.179 I (5179) UI: DeviceEventNotify, got DEVICE_NOTIFY_TYPE_SKYTUNE_SERVICE_AUTO_DATA
0:00:05.395 I (5395) SKYTUNE: validateToken, tokenValidTime = 14400 seconds
0:00:05.395 I (5395) SKYTUNE: Check for update..., 0
0:00:05.607 I (5607) SKYTUNE: skytuneTask, Send bye to skytune
0:00:05.746 I (5746) UI: setScreenState, NULL --> MENU
0:00:05.966 I (5966) SKYTUNE: checkUpdateCallback, firmware up-to-date
0:00:06.588 I (6588) READER: setPlayerState, CONNECTING_TO_SERVER -> BUFFERING, stopCode = -1
0:00:07.599 I (7599) SKYTUNE: checkDbCallback, dB up-to-date

Okay, we're connected to BBC Radio 4 FM, set the correct UI screen and begin buffering. We're about ten seconds since startup.

For what it is worth, the current Radio Four FM URL is given as http://open.live.bbc.co.uk/mediaselector/6/redir/version/20/mediaset/audio-syndication-vlow/proto/http/transferformat/hls/vpid/bbc_radio_fourfm.

This redirects to http://a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/nonuk/sbr_vlow/ak/bbc_radio_fourfm.m3u8 (note that it has detected my location and is providing a "non UK" URL).

And the m3u8 file gives the stream URL as http://as-hls-ww-live-akamaized.net/pool_904/live/ww.bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d48000.norewind.m3u8.

This second m3u8 file (oh FFS!) then provides a list of relative URLs in the form bbc_radio_fourfm-audio=48000-261991568.ts, each part giving about 46KiB of data. You'll need a player capable of handling chunked streaming to keep getting the parts to assemble to form the data stream.
CustomRadioPlayer on Android doesn't handle this. Luckily Chrome (and my internet radio!) do. But it's a pain in the arse when so many other stations just provide a simple link to the stream.

Notice the timestamp of when buffering status is changed to playing. It has buffered about three seconds. My settings asked for a five second buffer.

0:00:07.756 I (7756) UI: setScreenState, MENU --> PLAYER
0:00:10.211 I (10211) READER: setPlayerState, BUFFERING -> PLAYING, stopCode = -1
0:00:10.212 I (10212) setRampVolume: Target volume = 20, rate = 1
0:00:10.223 I (10223) MEDIA_CTRL: MEDIA_CTRL_EVT_PLAY mode:0, src:0, AudioInfo: 0, 0, 0, 0, 0, 0

Now a lot of guff to work out what the data is, and to set up the necessary decoding. Yes, the ESP32 is decoding AAC in realtime.

0:00:10.225 I (10225) PLAYER_HELPER: Stop helper AudioInfo: 0, 0, 0, 0, 0, 0
0:00:10.234 W (10234) SKYTUNE: skytuneReportStationStatus, OK=1, time=0
URI: raw://from.pcm/to.aac#i2s
0:00:10.242 W (10242) ELLIS_AUDIO: Initial download speed 286Kbps
0:00:10.244 W (10244) SOFT_CODEC: CodecStop, have no codec instance,0x0
0:00:10.259 I (10257) PLAYER_HELPER: Decoder only
0:00:10.263 I (10263) I2S_STREAM: I2sStream running, stream type 0, num 0
0:00:10.271 I (10270) MEDIA_HAL: Codec mode DECODE
0:00:10.276 I (10276) SOFT_CODEC: softdecoder task running & wait; type aac
0:00:10.283 I (10283) SOFT_CODEC: Before open:0 0, 0 0 0
0:00:10.292 I (10292) AACG_DECODER: new audio song
0:00:10.295 I (10294) AACG_DECODER: this audio is RAW AAC
0:00:10.339 I (10339) AACG_DECODER: I2S setup: sample_rate = 48000 : channels = 2
0:00:10.339 W (10339) SOFT_CODEC: metadata-set, 12 3fa115a8, 48000 2 16 5
0:00:10.344 I (10344) I2S_STREAM: STREAM_SETUP_RATE=48000, channel=2, bits=16, bps=192000,time=-1ms
0:00:10.355 I (10355) I2S: APLL: Req RATE: 48000, real rate: 47999.961, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 12287990.000, SCLK: 1535998.750000, diva: 1, divb: 0
0:00:10.369 I (10369) AACG_DECODER: m4a sampleRate=48000, Channels=2, frameSize=2048

After about twelve seconds, BBC Radio 4 FM begins playing.

When a station is connected, the radio provides some technical information on the screen like "AAC, 49Kbps, 48000Hz, 2 ch". After a few seconds, it switches to showing some information on the station, but since BBC doesn't include any embedded identity, it just shows the same information over again.

0:00:13.758 W (13758) SKYTUNE: skytuneReportStationStatus, codec=AAC, sampleRate=48KHz, bitRate=49Kbps

After a few seconds more, the backlight dims down to its low level.

0:00:20.688 I (20688) setBacklightFade: 3% in 2000mS

After about fifteen seconds, I press the power button. Since the radio is being powered from battery, it will switch itself off. The button is read a few times, it needs to be held to turn off. A simple press goes into sleep mode, but only if we're running from AC.

0:00:34.572 I (34572) UI: key = 0x300
0:00:34.572 I (34572) setBacklight: 800px
0:00:34.813 I (34812) UI: key = 0x8300
0:00:34.928 I (34928) UI: key = 0x300
0:00:34.942 I (34942) UI: key = 0x8300
0:00:35.117 I (35117) UI: key = 0x300

The first step of the shutdown is to stop the stream playing.

The messed up error message below (AACG_DECODER) is because the error message was triggered at exactly the same time as the "Stop helper" message, and it was in-lined in the middle of the message. Hmmm...

0:00:37.319 I (37319) PLAYER: stopPlay, ENTER
0:00:37.319 W (37319) PLAYER: Wait for reader stop...
0:00:37.675 E (37675) nossl_connect: Aborted
0:00:37.675 E (37675) ellis_HlsMediaPlaylist_v2: Error connect ... 1
0:00:37.693 I (37693) READER: setPlayerState, PLAYING -> STOPPING, stopCode = 5
0:00:38.176 W (38176) kill_player: Wait for player stop...
0:00:38.196 0:00:38.196 E (38196) AACG_DECODER: CodecOutput: output aborted 0 8192
I (38196) PLAYER_HELPER: Stop helper AudioInfo: 0, 0, 0, 0, 0, 0
0:00:38.198 I (38198) AACG_DECODER: aac close
0:00:38.209 I (38209) SOFT_CODEC: softdecoder task deleted
0:00:38.301 I (38301) SOFT_CODEC: softdecoder stopped
0:00:38.301 W (38301) I2S_STREAM: I2sStream type 0 req stop, last time is 0
0:00:38.303 I (38303) I2S_WRITER: End of stream, read_write_len=4096, stream->_block_write=4096, stream type=0 (line: 211)
0:00:38.315 I (38315) MEDIA_HAL: Codec stop DECODE
0:00:38.322 I (38322) I2S_STREAM: deleted stream type=0, outSize=0
0:00:38.324 I (38324) I2S_STREAM: I2sStream type 0 stopped
0:00:38.333 I (38333) MEDIA_CTRL: MEDIA_CTRL_EVT_STOP,mode:0 resume: 1
0:00:38.340 W (38340) PLAYER_HELPER: Recover Status(455), status:0, mode:0, errMsg:0, mediaSrc:0
0:00:38.350 I (38350) PLAYER_HELPER: Recover Position(443), codecPos:0 skipData:0
0:00:38.358 I (38358) MEDIACTRL_TAG: Current Player Info: status:0,mode:0,errMsg:0,src:0, Func:rawStopByCtrl, Line:1146

0:00:38.371 W (38371) decodeRadioTask: LEAVE
0:00:38.375 W (38375) kill_player: Wait for player stop...END
0:00:38.381 W (38381) ec_handle_https_url: Exit
0:00:38.386 I (38386) READER: setPlayerState, STOPPING -> STOPPED, stopCode = 5
0:00:38.394 I (38394) READER: tskRead, waiting for a START_PLAY
0:00:38.685 W (38685) PLAYER: Wait for reader stop...End
0:00:38.897 I (38897) PLAYER: stopPlay, LEAVE

Now the station has stopped playing, perform a network disconnection.

0:00:39.172 W (39172) skytuneTask: Wait for resume...
0:00:39.280 I (39280) SKYTUNE: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.280 I (39280) READER: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.286 I (39286) UPNP: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.294 I (39294) WebServer: webServerEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.303 I (39303) UI: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.312 I (39312) NETWORK: wifiStop, ENTER
0:00:39.316 I (39316) wifi:0:00:39.317 state: run -> init (0)0:00:39.317 
0:00:39.323 I (39323) wifi:0:00:39.323 pm stop, total sleep time: 0 us / 36851110 us
0:00:39.330 
0:00:39.332 I (39332) wifi:0:00:39.332 new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:10:00:39.332 
0:00:39.342 I (39342) NETWORK: +JAP:DISCONNECTED,8
0:00:39.346 I (39346) NETWORK: STA --> NONE
0:00:39.351 I (39351) SKYTUNE: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.359 I (39359) READER: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.368 I (39368) UPNP: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.376 I (39376) WebServer: webServerEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.385 I (39385) UI: DeviceEventNotify, DEVICE_NOTIFY_NETWORK_DISCONNECTED
0:00:39.393 I (39393) NETWORK: +JAP:DISCONNECTED, LEAVE
0:00:39.401 I (39401) NETWORK: +WIFI:STA_STOP
0:00:39.404 I (39404) wifi:0:00:39.404 flush txq0:00:39.404 
0:00:39.409 I (39409) wifi:0:00:39.409 stop sw txq0:00:39.409 
0:00:39.415 I (39415) wifi:0:00:39.416 lmac stop hw txq0:00:39.416 
0:00:39.421 I (39421) NETWORK: wifiStop, LEAVE
0:00:40.322 W (40322) powerOff: Wait for KEY inactive

And that's it. The device is now in power down mode. I'm not exactly sure how the power button works, as the ESP32 is not in itself running because it can sit for days and not consume any power, and the first thing the ESP32 does is boot up. I'm guessing the chip goes into full power down mode, and the power button is somehow partially connected to the CHIP_PU pin to bring it back out of power down. And the reason why it acts a bit weird at the beginning is because the button pulls that pin high to start up the chip, but it's the firmware that latches the pin high (so the button can be released and the device will keep on running).

Well, not what I planned on doing today. But as usual, I didn't have anything specific planned, other than maybe mowing but, well, not this weekend. ☺

Your comments:

Please note that while I check this page every so often, I am not able to control what users write; therefore I disclaim all liability for unpleasant and/or infringing and/or defamatory material. Undesired content will be removed as soon as it is noticed. By leaving a comment, you agree not to post material that is illegal or in bad taste, and you should be aware that the time and your IP address are both recorded, should it be necessary to find out who you are. Oh, and don't bother trying to inline HTML. I'm not that stupid! ☺ ADDING COMMENTS DOES NOT WORK IF READING TRANSLATED VERSIONS.
 
You can now follow comment additions with the comment RSS feed. This is distinct from the b.log RSS feed, so you can subscribe to one or both as you wish.

Rick, 18th February 2023, 20:31

The dump is width-restricted because if not, or if given a percentage width, the entire width of the long lines (such as the Radio Four URL) would massively screw up the formatting.    Visual coherence takes precedence, and the dump parts have scroll bars should you care to read all of the waffle. ☺

David Pilling, 18th February 2023, 23:35

Good hack...

Add a comment (v0.11) [help?] . . . try the comment feed!
		Your name
		Your email	(optional)
		Validation	Are you real? Please type 18533 backwards.
		Your comment