Warning: Can't synchronize with repository "(default)" (No changeset 96d22ec3fa3ef6de3ea8dc0d7d398adc9aa071cf in the repository). Look in the Trac log for more information.

Ticket #361 (closed defect: invalid)

Opened 4 years ago

Last modified 4 years ago

ogsmd mixes unsolicited and solicited responses

Reported by: mickey Owned by: mickey
Priority: blocker Milestone: cornucopia-0.10
Component: framework/ogsmd Version: milestone5
Keywords: Cc:

Description

ogsmd output: 

2009.02.20 03:27:47 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: _readyToSend: watch timeout = None       
2009.02.20 03:27:47 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: sending 19 bytes: 'AT+CNMI=2,1,2,1,1\r\n'
2009.02.20 03:27:47 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: _readyToRead: watch timeout = 291        
2009.02.20 03:27:47 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: got 68 bytes from: '%CSTAT: EONS, 0\r\n%CSTAT: PHB, 0\r\n%CSTAT: SMS, 1\r\n\r\n+CGREG: 2\r\n\r\nOK\r\n'                                                                   
2009.02.20 03:27:47 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: COMPLETED 'AT+CNMI=2,1,2,1,1' => ['%CSTAT: EONS, 0', '%CSTAT: PHB, 0', '%CSTAT: SMS, 1', '+CGREG: 2', 'OK']                                                               
2009.02.20 03:27:47 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: _readyToSend: watch timeout = None       
2009.02.20 03:27:49 ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/6>: _readyToRead: watch timeout = None

abyss output: 

2009-02-20T02:27:47Z: multiplexer.vala:593: device_io_can_read for fd 4                                                          
2009-02-20T02:27:47Z: multiplexer.vala:498: 0710 -> should read max 4095 bytes to 0x29efd                                        
2009-02-20T02:27:47Z: multiplexer.vala:503: read 64 bytes from fd 4                                                              
2009-02-20T02:27:47Z: consts.vala:77: <<< 7E 09 EF 25 43 53 54 41 54 3A 20 45 4F 4E 53 2C  ~..%CSTAT: EONS,                      
2009-02-20T02:27:47Z: consts.vala:77: <<< 20 30 0D 0A 40 7E 7E 09 EF 25 43 53 54 41 54 3A   0..@~~..%CSTAT:                      
2009-02-20T02:27:47Z: consts.vala:77: <<< 20 50 48 42 2C 20 30 0D 0A 40 7E 7E 09 EF 25 43   PHB, 0..@~~..%C                      
2009-02-20T02:27:47Z: consts.vala:77: <<< 53 54 41 54 3A 20 53 4D 53 2C 20 31 0D 0A 40 7E  STAT: SMS, 1..@~                      
2009-02-20T02:27:47Z: consts.vala:83: <<<                                                                                        
2009-02-20T02:27:47Z: multiplexer.vala:561: 0710 -> say '0710 packet ok: chan 2, type 0xEF, data[0] 0x25, len 17                 
2009-02-20T02:27:47Z: multiplexer.vala:529: 0710 -> deliver 17 bytes for channel 2                                               
2009-02-20T02:27:47Z: channel.vala:139: <Channel 4 (ogsmd.gprs) connected via /dev/pts/9>: can read from Pty                     
2009-02-20T02:27:47Z: channel.vala:142: :::read 1 bytes                                                                          
2009-02-20T02:27:47Z: multiplexer.vala:443: channel -> submit_data                                                               
2009-02-20T02:27:47Z: multiplexer.vala:512: 0710 -> should write 6 bytes                                                         
2009-02-20T02:27:47Z: consts.vala:83: >>> 7E 13 EF 0D 65 7E  ~...e~                                                              
2009-02-20T02:27:47Z: multiplexer.vala:521: wrote 6/6 bytes to fd 4                                                              
2009-02-20T02:27:47Z: multiplexer.vala:561: 0710 -> say '0710 packet ok: chan 2, type 0xEF, data[0] 0x25, len 16                 
2009-02-20T02:27:47Z: multiplexer.vala:529: 0710 -> deliver 16 bytes for channel 2                                               
2009-02-20T02:27:47Z: channel.vala:139: <Channel 2 (ogsmd.unsolicited) connected via /dev/pts/6>: can read from Pty              
2009-02-20T02:27:47Z: channel.vala:142: :::read 19 bytes                                                                         
2009-02-20T02:27:47Z: multiplexer.vala:443: channel -> submit_data                                                               
2009-02-20T02:27:47Z: multiplexer.vala:512: 0710 -> should write 24 bytes                                                        
2009-02-20T02:27:47Z: consts.vala:77: >>> 7E 0B EF 41 54 2B 43 4E 4D 49 3D 32 2C 31 2C 32  ~..AT+CNMI=2,1,2                      
2009-02-20T02:27:47Z: consts.vala:83: >>> 2C 31 2C 31 0D 0A 9A 7E  ,1,1...~                                                      
2009-02-20T02:27:47Z: multiplexer.vala:521: wrote 24/24 bytes to fd 4                                                            
2009-02-20T02:27:47Z: multiplexer.vala:561: 0710 -> say '0710 packet ok: chan 2, type 0xEF, data[0] 0x25, len 16                 
2009-02-20T02:27:47Z: multiplexer.vala:529: 0710 -> deliver 16 bytes for channel 2                                               
2009-02-20T02:27:47Z: multiplexer.vala:593: device_io_can_read for fd 4                                                          
2009-02-20T02:27:47Z: multiplexer.vala:498: 0710 -> should read max 4095 bytes to 0x29efd                                        
2009-02-20T02:27:47Z: multiplexer.vala:503: read 18 bytes from fd 4                                                              
2009-02-20T02:27:47Z: consts.vala:77: <<< 7E 09 EF 0D 0A 2B 43 47 52 45 47 3A 20 32 0D 0A  ~....+CGREG: 2..                      
2009-02-20T02:27:47Z: consts.vala:83: <<< 40 7E  @~                                                                              
2009-02-20T02:27:47Z: multiplexer.vala:561: 0710 -> say '0710 packet ok: chan 2, type 0xEF, data[0] 0x0D, len 13                 
2009-02-20T02:27:47Z: multiplexer.vala:529: 0710 -> deliver 13 bytes for channel 2                                               
2009-02-20T02:27:47Z: multiplexer.vala:593: device_io_can_read for fd 4                                                          
2009-02-20T02:27:47Z: multiplexer.vala:498: 0710 -> should read max 4095 bytes to 0x29efd                                        
2009-02-20T02:27:47Z: multiplexer.vala:503: read 11 bytes from fd 4                                                              
2009-02-20T02:27:47Z: consts.vala:83: <<< 7E 09 EF 0D 0A 4F 4B 0D 0A 40 7E  ~....OK..@~                                          
2009-02-20T02:27:47Z: multiplexer.vala:561: 0710 -> say '0710 packet ok: chan 2, type 0xEF, data[0] 0x0D, len 6                  
2009-02-20T02:27:47Z: multiplexer.vala:529: 0710 -> deliver 6 bytes for channel 2                                                
2009-02-20T02:27:49Z: multiplexer.vala:593: device_io_can_read for fd 4                                                          
2009-02-20T02:27:49Z: multiplexer.vala:498: 0710 -> should read max 4095 bytes to 0x29efd                                        
2009-02-20T02:27:49Z: multiplexer.vala:503: read 19 bytes from fd 4

Abyss output clearly shows that everything is still in order on muxing side. The results are overtaking the request in ogsmd though. I will study the code to see where and how this can happen.

Change History

comment:1 Changed 4 years ago by mickey

  • Priority changed from major to blocker

OMG! I have been oh so blind, but I just yesterday I have been blessed with open eyes.

Drama aside, it looks like I finally found the 100% foolproof method to identify unsolicited responses, whether they're standalone or come mixed in solicited responses. I was so sure since the beginning of ogsmd that such a method exists, but I haven't seen the \r\n in so many messages :D

Stay tuned.

comment:2 Changed 4 years ago by mickey

  • Status changed from new to closed
  • Resolution set to invalid
Note: See TracTickets for help on using tickets.